Что не так с cProfile в Python
Некоторое время назад с коллегой обсуждали вопрос профилирования программ на Python (haters gonna hate, flamers gonna flame). Он сказал, что использует gprof2dot для пост‑обработки данных cProfile, в ответ я высказал мысль, о том, что было бы хорошо использовать более современные средства профилирования. И задумался, а можно ли какие‑то из существующих инструментов приспособить для работы с данными в формате pstat (это внутренний недокументированный формат cProfile), но которые более удобные и дают больше возможностей для анализа.
Disclaimer
Всё это в равной степени относится и к profile и поэтому я буду упоминать только cProfile, но иметь в виду их оба два.
Я подразумеваю, что у вас есть какой-то опыт использования профайлеров и профайлеров в Python, поэтому какие-то моменты опущу в описании.
Оглавление
Введение
В чём, на мой взгляд, проблема с gprof2dot. Основное его предназначение в создании изображения графа вызовов. В случае, если граф содержит большое количество функций, то изображение, либо должно иметь очень высокое разрешение, либо на нём будет скрыта часть вызовов функций. В обоих случаях это доставляет неудобство и замедляет процесс профилирования.
Для работы с данными pstat есть различные инструменты, которые в той или иной мере пытаются упростить процесс анализа результатов профилирования, за счёт повышения уровня интерактивности. Условно их можно разделить на три класса:
Инструменты, использующие
dot.exe/GraphVizдля построения графа вызовов.Инструменты, строящие иерархические карты.
Инструменты, строящие FlameGraph.
К первому классу можно отнести xdot.py от автора gprof2dot. Это десктопное приложение, с довольно ограниченным набором функциональности, кроме операций масштабирования, не предоставляет никаких других функций.
KCacheGrind (или QCacheGrind под Windows) также имеет функциональность для работы с графом вызовов. Позволяет проваливаться в функции (так называемый drill-down), для выбранной функции строит цепочку вызовов.
KCacheGrind также относится и ко второму классу, который основывается на построении иерархических карт. Для выбранной функции строит карту, на которой, чем больше площадь у фигуры, тем большее время эта функция занимает в статистике. Есть статья Профилирование python приложений, в которой рассказано, как используя pyprof2calltree подготовить данные для KCacheGrind. Есть и другие приложения со сходной функциональностью (например, snakerunner), но KCacheGrind проверенный временем инструмент.
К третьему классу можно отнести SnakeViz, который позволяет построить Icicle‑график (это аналог FlameGraph, но растёт не вверх, а вниз). Предоставляет навигацию по этому графику, позволяет проваливаться вниз по стеку и подниматься обратно. Имеет всю необходимую функциональность, но не очень удобный пользовательский интерфейс (на мой взгляд). Требует минимум зависимостей для установки.
Если SnakeViz может создать иерархический график, то и мы можем сделать тоже самое и использовать более удобные средства визуализации и анализа. Например, есть доступные онлайн speedscope, flamegraph.com или плагины для VSCode — vscode‑flamegraph, speedscope‑in‑vscode, austin‑vscode.
Если немного поискать в интернете, то можно найти flameprof, с помощью которого можно сконвертировать данные и получить svg изображение или текстовый файл, пригодный для загрузки в перечисленные выше приложения.
Казалось бы, задача решена и найдены подходящие инструменты, но нет.
Что не так с cProfile
Помимо того, что cProfile заметно замедляет выполнение программ при профилировании, данные, которые он при этом собирает и хранит, содержат ограниченное количество информации.
В pstat для каждой вызываемой функции хранится статистика, которая содержит следующее:
— количество вызовов (не считая рекурсивных вызовов);
— общее количество вызовов (с учётом рекурсивных вызовов);
— время, проведённое в самой функции (называется totaltime);
— время, выполнения функции с учётом вызовов других функций (cum_time, всегда больше или равно totaltime).
А также список функций, из которых вызывалась данная функция и такой же набор данных.
Используя эту информацию, gprof2dot строит граф вызовов, SnakeViz и flameprof иерархические графики, KCacheGrind иерархические карты. В этом и проблема — эти данные непригодны для этих целей.
И если в случае gprof2dot мы не имеем никаких ожиданий относительно иерархии вызовов (хотя получаемый граф и является направленным), то в случае SnakeViz, flameprof и аналогичных инструментов, мы ожидаем определённую иерархическую структуру у графиков. FlameGraph предполагает, что отображаемые на графике функции, потребляют тем больше времени выполнения, чем ниже они находятся по оси Y. Тогда, как информация, восстановленная из pstat, не позволяет это сделать.
Покажу на примере:
Пусть у нас есть две функции F1 и F2. Каждая функция предназначена для тестирования различных вариантов реализации бизнес‑функциональности. В данных функциях вызываются библиотечные функции, которые вызывают какие‑то свои функции и т. д. Граф вызовов выглядит примерно вот так:
pstat в этом случае будет хранить статистику для следующих пар функций:
F1 -> LFF2 -> LFLF -> CF
И имея эти данные, мы не можем определить, какая доля вызовов функции CF относится к F1, а какая к F2. Таким образом, все представления в иерархическом виде показывают недостоверные данные. Ни SnakeViz, ни flameprof, ни pyprof2calltree никаких корректировок не делают (что, наверное, разумно).
В SnakeViz вполне можно получить изображение, в котором вложенная функция потребляет больше времени, чем вызывающая. Здесь ничего удивительного, SnakeViz просто считывает информацию из pstat.
Например, на изображении ниже видно, что __setitem__ имеет накопленное время 70 мс, тогда как вызывающая функция update — 37 мс:
Пример ошибочной визуализации в SnakeViz
flameprof просто создаёт файл, на основе которого можно построить FlameGraph и в его случае информация просто суммируется, в результате вышележащие функции получают дополнительный »вес», что опять же не позволяет делать нам правильные выводы об интересующих нас функциях.
Пример визуализации FlameGraph в плагине austin‑vscode
Отдельно стоит упомянуть рекурсивные вызовы, которые появляются при импортах пакетов и пронизывают многие вызовы и от которых сложно избавиться.
Так в чём же проблема?
На мой взгляд, проблема в том, что в силу ограниченности формата хранения данных, встроенные профайлеры profile/cProfile пригодны только для узкого круга задач, в основном (имхо), для профилирования приложений с несложным графом вызовов. Также отсутствует какая‑либо поддержка многопоточного и асинхронного выполнения.
В случае если используется профилирование всего приложения (через python -m cProfile file.py) информация о тяжёлых вызовах размывается — да, мы увидим, что какая‑то функция потребляет бОльшую часть времени, но кто, откуда, с какими параметрами её вызывал мы не увидим, что приведёт нас к необходимости искать другие инструменты или делать какие‑то наколенные решения.
В случае использования декоратора для профилирования отдельных функций, мы также можем столкнуться с проблемой, описанной выше — не будет достоверной информации о вызовах, если »тяжёлая» функция вызывается через несколько цепочек. В результате мы либо опять же вынуждены использовать другие инструменты, либо вручную смещать декоратор вниз по стеку, что сильно удлиняет процесс профилирования.
А если мы всё равно вынуждены использовать другие инструменты, то зачем пользоваться profile/cProfile вообще?
cProfile не является профайлером
Если посмотреть на историю изменения файла _lsprof.c (в котором находится реализация cProfile), то можно увидеть не очень большое количество коммитов. Впервые он был добавлен в 2006 году и с тех пор принципиально не менялся до 2023 года, когда был выполнен переход на новое API для профилирования (sys.monitoring). Все коммиты, в основном космитические, связанные с изменениями самого Python. Формат хранения данных при этом каких‑то существенных изменений не претерпел. Функционального развития тоже не было.
Поэтому я думаю, что хотя cProfile и планировался как профайлер, но вместо этого получился пример использования внутреннего API для построения инструментирующих (или детерминированных) профайлеров. Впрочем, даже в этом случае он не покрывает все необходимы варианты, например, асинхронные вызовы, многопоточное выполнение никак не разделяется в результатах профилирования.
Другие инструменты
В повседневной работе я использую austin и viztracer.
austin является статистическим (или семплирующим) профайлером (т. е. он периодически собирает информацию о выполняющихся в данный момент функциях, мелкие функции поэтому может пропустить), строит FlameGraph и имеет удобные инструменты для визуализации, в том числе и плагин для vscode. Его данные можно загрузить в speedscope или аналогичные инструменты.
К семплирующим профайлерам также относятся py‑spy, pyinstrument, scalene и другие. Обещается, что такие профайлеры вносят меньше задержек в профилируемое приложение.
viztracer является детерминированным профайлером (т. е. собирает информацию о каждом вызове функций), сохраняет данные в формате Google Trace Event, визуализация построена на основе Perfetto (расширенной версии профайлера, встроенного в Google Chrome и Edge). Данные также можно сконвертировать в формат, пригодный для построения FlameGraph. Также есть yappi, но с ним опыта не имел.
А что с gprof2dot?
Интересным итогом стало то, что после, того как я разобрался с форматом хранения pstat, я теперь склоняюсь к тому, что gprof2dot (и аналоги) лучше всего подходят для графического представления результатов профилирования cProfile.
Спасибо за внимание.
Habrahabr.ru прочитано 1736 раз
