Эта статья имеет определенный общий характер для устранения утечек памяти вне кучи, вызванных netty, и я надеюсь, что она вдохновит вас.
задний план
В последнее время я работаю над промежуточным программным обеспечением для длинных соединений на основе веб-сокетов, и сервер использует реализациюsocket.ioПротокол (основанный на протоколе websocket, обеспечивающий возможность понижения версии при длительном опросе)netty-socketioFramework, фреймворк реализован netty, так как я знаком с netty, и сравнение тоже реализованоsocket.ioДругие фреймворки протокола, репутация этого фреймворка лучше, поэтому этот фреймворк выбран в качестве базового ядра.
Любая инфраструктура с открытым исходным кодом не может избежать существования ошибок.Когда мы использовали эту инфраструктуру с открытым исходным кодом, мы столкнулись с ошибкой утечки памяти вне кучи.Поскольку мы знакомы с netty, мы хотели бросить вызов и найти ошибку (баг), а затем явление и процесс устранения неполадок, студенты, которые хотят увидеть вывод, могут напрямую перейти к окончательному резюме.
Феномен
Однажды утром неожиданно получил сигнал тревоги, большое количество 5xx на сервере nginx.
Мы используем nginx в качестве семиуровневой нагрузки веб-сокета на стороне сервера, а всплеск 5xx обычно указывает на то, что сервер недоступен. Поскольку текущая тревога nginx не подразделяет, какая машина недоступна, далее перейдите в кат (Комментарий к унифицированной платформе мониторинга Meituan), чтобы проверить индикаторы всего кластера, и найдите следующие два исключения.
В то же время машина ломает gc, и в то же время поток jvm блокируется
Затем начинается долгий путь устранения утечек памяти вне кучи.
Процесс устранения неполадок
Этап 1. Подозрение на log4j2
Заблокировано большое количество потоков.Первое, что приходит в голову, это определить, какие потоки заблокированы.Наконец, обнаруживается, что log4j2 безумно проигрывает логи, из-за чего поток netty nio блокируется (потому что сцена не сохранялась в время, поэтому скриншот отсутствует) После того, как поток nio заблокирован, наш сервер не может обработать запрос клиента, что составляет 5xx для nginx.
Далее смотрим конфигурационный файл log4j2
Я обнаружил, что приложение, выведенное на консоль, забыло его прокомментировать, поэтому мое первоначальное предположение состоит в том, что этот проект печатает слишком много журналов, а log4j2 выводит на консоль синхронную печать, блокируя печать Затем поместите эту строку всех машин в строку. Закомментировал и подумал, что дело сделано.Не ожидал, что через несколько дней сигнализация 5xx снова постучит в дверь.Похоже, что эта проблема не так проста.
Этап 2: появляются подозрительные журналы
Дальше мне остается только стиснуть зубы и проверить логи, проверить логи до и после точки отказа и найти подозрительное место
За очень короткий промежуток времени,failed to allocate 64(bytes) of direct memory(...)Лог (более десятка лог-файлов в миг, сотни М на лог-файл), в лог кидается инкапсулированная сама по себе nettyOutOfDirectMemoryError, Грубо говоря, не хватает памяти за пределами кучи, а netty уже жалуется.
Утечка памяти вне кучи, я пошел, я немного расстроился, когда услышал этот термин, потому что устранение этой проблемы так же сложно, как утечка памяти в языке C. Первое, что пришло мне в голову, это проверить, не было ли аномалии перед вспыхнул ООМ, а потом проверяйте кота и машину.Все сопутствующие индикаторы, все логи до лога ООМ были проверены, и исключения не обнаружено! В этот момент я начал ругаться...
Этап 3: Обнаружение источника OOM
Но нет никакого способа, я могу только смотреть на эти неприятные журналы OOM в оцепенении, пытаясь получить ответ в моих глазах. Когда я был в растерянности, перед моими глазами вдруг вспыхнул свет, и несколько строк логов под ООМ стали ослепляющими (почему я раньше внимательно не проверил логи? Наверное, меня испугали слова off- утечка памяти в куче). ==), эти строки....PlatformDepedeng.incrementMemory().... Позвольте мне.Получается, достаточно ли памяти вне кучи вычисляет сама netty.Можем ли мы найти статистический код?После нахождения статистического кода мы можем увидеть статистическую логику внешней памяти в netty? Итак, затем пролистайте код и найдите эту логику, вPlatformDepedentв этом классе
Это место является операцией, которая подсчитывает используемую память вне кучи, счетчикDIRECT_MEMORY_COUNTER, если обнаруживается, что используемая память больше, чем верхний предел памяти вне кучи (указанный пользователем), выдается кастомная OOM Error, а текстовое содержимое в исключении именно то, что мы видим в логе .
Затем убедитесь, что эта функция вызывается при выделении памяти вне кучи.
Разумеется, каждый раз, когда netty выделяет память вне кучи, она будет засчитываться.Если подумать, идея проясняется, а настроение улучшается.
Этап 4: Отражение для мониторинга памяти вне кучи
Так как в мониторинге памяти вне кучи на кате нет аномалий (должно быть, что статистика не точная, она поддерживается на уровне 1М), и здесь мы подтверждаем, что памяти вне кучи около чтобы превысить верхний предел, и мы уже знаем, какое поле используется нижним слоем netty для статистики.Да, тогда первое, что нужно сделать дальше, это получить это поле путем отражения, а затем мы считаем использование off-heap память по нетти.
Поле статистики памяти вне кучиDIRECT_MEMORY_COUNTER, мы можем получить это поле через отражение, а затем регулярно проверять это значение, чтобы отслеживать рост памяти за пределами кучи netty.
Мы получаем это поле путем отражения и печатаем его каждую секунду, зачем мне это делать?
Поскольку, согласно нашему предыдущему анализу, перед вспышкой большого количества явлений OOM не было подозрительного явления, то есть только два случая, один из которых заключается в том, что в определенный момент внезапно выделяется большой объем памяти вне кучи для причина OOM, а другая — память вне кучи, она растет медленно, и после определенного момента последняя соломинка давит машину. После добавления этого кода он упаковывается и запускается.
Стадия 5: медленный рост или мгновенный всплеск?
После того, как код подключен к сети, начальная память составляет 16384 КБ (16 МБ). Это связано с тем, что мы используем оперативную память вне кучи. Размер блока по умолчанию составляет 16 МБ, поэтому нет необходимости слишком запутываться.
Через некоторое время воспоминание начало медленно парить, и не было никаких признаков освобождения.Через 20 минут воспоминание было следующим
На этом этапе предположение может быть вторым случаем, упомянутым выше, то есть OOM, вызванным медленным ростом памяти.Поскольку рост памяти слишком медленный, вес загрузки машины корректируется так, чтобы он был вдвое больше, чем у других машин, но это еще несколько уровней K. В росте этот день оказался пятницей, поэтому он просто дождался выходных, прежде чем открыть его.
После приятных выходных первое, что я сделал, приехав в компанию, это подключился к машине-трамплину, зашел на онлайн-машину, запустил tail -f и продолжил просмотр лога. нажмите Enter с нетерпением.
Как и ожидалось, память росла медленно, за один уик-энд память вне кучи взлетела почти до одного G. В это время я на самом деле подумал об идиоме: пока ты усердно работаешь, железный пестик станет иголка! Несмотря на то, что память вне кучи увеличивается на несколько K и несколько K, пока это продолжается, всегда будет время, когда память будет взорвана (верхний предел оперативной памяти вне кучи установлен на 2G).
В этот момент я снова начал спрашивать себя: почему память растет медленно и с чем? Поскольку наше приложение представляет собой веб-сокет, ориентированный на пользователя, будет ли каждый раз, когда пользователь заходит, после взаимодействия, а затем уходит, память будет немного расти, а затем не будет освобождаться? Имея в виду этот вопрос, я начал офлайн-симуляцию.
Фаза 6: Автономное моделирование
Запустите хороший сервис локально, и измените единицу мониторинга off-heap memory на B (т.к. локальный трафик небольшой, планируется подключение по одному клиенту), кроме того, локально используется непулируемая память ( номер памяти маленький, легко увидеть проблему), так что после запуска сервера консоль выводит следующую информацию
Когда клиентский доступ отсутствует, память вне кучи всегда равна 0, что и ожидается. Затем, с большим волнением, откройте браузер и введите URL-адрес, чтобы начать наше путешествие по симуляции.
Наш процесс моделирования: создайте новую клиентскую ссылку -> отключите ссылку -> создайте новую клиентскую ссылку -> снова отключите ссылку.
Как показано на рисунке выше, подключение и отключение — это установление и закрытие соединения, а журналы в зеленых прямоугольниках на рисунке выше — это жизненные циклы двух соединений соответственно. Мы видим, что память взлетает на 256B каждый раз, когда соединение закрывается, а затем не освобождается.На этом этапе проблема еще больше уменьшается.Должно быть, что при закрытии соединения срабатывает ошибка в фреймворке, и этот баг срабатывает до триггера.было выделено 256Б памяти, а потом баг сработал, а память не освободилась. После того, как проблема устранена, следующий шаг — начать отлавливать ошибки с помощью исходного кода!
Этап 7: Офлайн-расследование
Затем я перезапустил локальную службу и начал полный процесс устранения неполадок в автономном режиме. Глядя на событие отключения фреймворка netty-socketio (которое вызывается, когда клиентское веб-соединение закрывается), в основном очевидно, что память, примененная до и после события отключения, не освобождается.
Здесь, при использовании отладки идеи, необходимо выбрать приостановку только текущего потока, чтобы при одношаговой трассировке консоль по-прежнему могла видеть, что поток статистики памяти вне кучи печатает журнал.
После того, как клиент подключится, а затем закроется, точка останова входит вonDisconnectОбратный звонок, я намеренно задержался здесь на некоторое время, и обнаружил, что консольная память не парится (память 7Б пока не анализировалась, просто нужно знать, что после разрыва клиентского соединения мы держим точку останова, и память не начала увеличиваться. ), затем появилась волшебная сцена, я снял точку останова и дал программе запуститься
После сброса дебага память сразу взлетела! ! К этому времени я уже знал, что жук не улетит далеко. При отладке текущий поток приостанавливается, значит должно быть, что текущий поток куда-то подал заявку на off-heap память, а потом ее не освобождают.Далее поторопитесь и углубитесь в исходный код.
Каждый раз, когда я прохожу, я наблюдаю, как память консоли взлетает, и вскоре мы приходим к этому месту.
До выполнения этой строки память консоли по-прежнему составляет 263Б, а потом, после выполнения этой строки, сразу увеличивается с 263Б до 519Б (до 256Б)
Таким образом, объем ошибки был еще более уменьшен: я закончил работу программы, выпустил ее, а затем клиент снова подключился, точка останова была сбита вclient.send()Эта строка, затем закрыть клиентское соединение, а затем напрямую ввести этот метод, последующий процесс немного длинный, потому что он связан с механизмом распространения времени netty, здесь он опущен, и, наконец, я следовал следующему коду,handleWebsocket
В этом месте я посмотрел на очень подозрительное место, на строку выше точки останова на картинке выше, вызываяencoderПосле выделения куска памяти, после звонка, наш пульт будет сразу 256Б, поэтому я подозреваю, что примененная здесь память не освободилась, и он будет звонить сюда дальшеencoder.encodePacket()Метод, я думаю, состоит в том, чтобы записать содержимое пакета данных в эту память объемом 256 Б в двоичной форме. Затем я следую этому коду кодирования и после одноэтапного выполнения нахожу эту строку кода.
Этот код преобразует значение поля в пакете в char, однако, когда я использую идею для предварительного выполнения, он выдает сердитый NPE! ! То есть после того, как фреймворк претендует на кусок памяти, в момент энкодера, я сам GG, и я вырыл себе глубокую яму NPE, и в итоге память не может быть освобождена (крайний слой вышел логика освобождения памяти -of-heap, которая сейчас не может быть исполнена).Когда она придет), а потом сохранять все больше и больше, и сохранять все больше и больше, до последней капли память вне кучи взорвалась вот так.Заинтересованные читатели исходный код здесь можете анализировать сами.Из-за нехватки места я не буду анализировать его здесь.
Этап 8: Исправление ошибок
Теперь, когда ошибка найдена, следующим шагом будет ее устранение. Здесь нам нужно только решить исключение NPE, и его можно исправить. Наша цель - сделать этоsubTypeПоле не пустое, мы сначала находим, где этот пакет определен через стек вызова потока идеи.
Мы нашли панель идеи отладчика, посмотрели на объект пакета, а затем переместили курсор в онлайн, чтобы найти его со скоростью света.Оказывается, место, где определяется объект пакета, действительно появилось в коде перед нами, и мы это проверили.subTypeЭто поле действительно пустое.Далее легко решить ошибку.
Этому полю можно присвоить значение.Поскольку это событие закрытия соединения, я присвоил ему поле с именем DISCONNECT (для более глубокого изучения протокола socket.io позже).В любом случае, это ошибка, когда соединение закрывается. Триггер, это немного грубо! ==.
Процесс решения этого бага таков: скачайте исходники этого фреймворка на локалку, а потом добавьте эту строчку.Напоследок пересоберу, поменяю имя в pom, и запущу на склад нашей компании, чтобы мой проект можно использовать напрямую.
После исправления ошибки обычно заходите на github, чтобы найти коммит, вызвавший ошибку.
dznКоммиттер напишет такой явный баг, а время 30 марта этого года, накануне запуска проекта!
Этап 9. Автономная проверка
После того, как все готово, сначала выполним локальную проверку.После того, как служба поднята, я судорожно устанавливаю соединения, судорожно отключаю соединения и наблюдаю за ситуацией с памятью вне кучи.
Молодец, как ни отключай, а вне кучи памяти не прибавилось.Пока баг в принципе исправлен.Конечно на последнем шаге пушим код на онлайн проверку.
Этап 10: онлайн-проверка
В этой онлайн-проверке мы избегали относительно грязного метода логирования.Мы распылили этот индикатор памяти вне кучи на cat, а затем некоторое время наблюдали за ситуацией с памятью вне кучи.
Мы обнаружили, что через некоторое время память вне кучи стала стабильной, и наше путешествие по отлову ошибок завершено! Наконец, позвольте мне подвести итог местной поездки по поиску жуков.
Суммировать
1. Не бойтесь утечек памяти out-of-heap, анализируйте внимательно и терпеливо, всегда можно найти идеи, нужно больше читать логи и больше анализировать.
2. Если вы используете netty off-heap memory, то вы можете контролировать использование off-heap памяти самостоятельно, без использования сторонних инструментов, здесь я использую рефлексию для получения off-heap памяти.
3. Постепенно сужайте область, пока ошибка не будет найдена вами. Когда вы подтверждаете, что выполнение определенного потока приводит к ошибке, вы можете выполнить одноэтапное или двоичное выполнение.После обнаружения строки кода следуйте этому коду, а затем продолжите одноэтапное выполнение или двоичное выполнение, чтобы найти последнюю ошибку. .код, этот метод опробован и протестирован, и, в конце концов, всегда можно найти ошибки.
4. Быть опытным в отладке идей, чтобы вы могли ловить ошибки молниеносно.Здесь наиболее распространенным методом отладки является предварительное выполнение выражений, и через стек вызовов потока, глядя на объект, вы можете понять определение этого объекта. , присваивание и т.д.
Наконец, я желаю, чтобы каждый мог найти свои собственные ошибки!