На этапе нагрузочного тестирования обнаружилась утечка памяти в контейнере приложения, которое я разрабатываю.
До этого мне приходилось сталкиваться с утечками в JS в браузере, я даже доклад про это рассказывал, но в этот раз утечка была в агенте на Python, поэтому браузерные девтулзы там не помогли бы — пришлось разбираться в этом вопросе заново.
Профилировать я начал с pytest-memray.
Это было проще всего — подключаешь плагин pytest-memray к уже написанным тестам на pytest, запускаешь тесты как обычно, и получаешь на выходе топ 5 функций, которые за время работы тестов аллоцировали наибольшее количество памяти.
Memray
Отчёт pytest-memray не самый подробный — это просто текст.
Поэтому я решил перейти на обычный memray, который работает независимо от pytest и способен выдавать самые разные форматы отчетов. Я использовал Flamegraph-диаграмму и линейный график.
Подготовил скрипт для memray, который вызывал бы моего агента со всеми возможными наборами параметров, сделал заглушки на вызовы гигачата и других сервисов, прогнал этот скрипт 10000 раз — и увидел тот самый классических восходящий график использования памяти, а так же статистику по использованию памяти во всех вызванных функциях.
Причина утечки
Работа с результатами отчета привела меня к файлу с таким кодом:
from prometeus_client import Histogram
metrics = Histogram(
name="my_service",
labelsnames=("sender", "status", "time"),
)
def send_metrics(
sender: StrEnum,
status: StrEnum,
time: float
):
metrics.labels(
sender=sender,
status=status,
time=time
).observe(time)
Респект, если вы уже догадались, в чём тут причина)) Я гадать не стал, признаюсь, сразу пошел в гигачат. Это не реклама, кстати, просто из корпоративной сети мне доступен только он. Но я и не жалуюсь, т.к. гигач сразу указал на причину утечки — лейбл time.
Почему именно time, а не, например, status?
У лейбла status набор возможных принимаемых значений ограничен енумом — либо "success", либо "error" (это для примера). Соответственно, сколько бы я ни гонял свой скрипт, хоть 5 раз, хоть 500, в метриках сохранится только два варианта значений этого лейбла — "success" или "error".
У лейбла sender значений чуть больше, но тоже вполне ограниченное количество.
А вот лейбл time в моём случае означал время обработки запроса. С типом float. То есть, запрос мог обработаться, например, за 0.5 секунд со статусом "success". А мог за 0.2 со статусом "error". Или за 0.10002 секунд, 0.037261846 секунд, 0.137, 0.9989 и ещё за огромное количество вариаций. Умножьте это количество вариаций на комбинации с остальными лейблами, которых тоже на самом деле было не три, а чуть больше, и вы поймёте, почему я в воскресенье вечером про утечки памяти пишу))