При сравнении времени Python-функции без профайлера и под cProfile результат под профайлером заметно хуже: какой механизм нужно учесть, чтобы не принять это замедление за свойство алгоритма?
cProfile сам вносит измеримый накладной расход: он перехватывает события вызова и возврата функций, измеряет их длительность и обновляет статистику. Поэтому время профилируемого запуска нельзя напрямую считать производительностью алгоритма; его используют прежде всего для поиска горячих участков и сравнения структуры затрат.
Особенно сильно искажение заметно в коде с большим количеством вызовов коротких Python-функций. После обнаружения кандидата на оптимизацию результат нужно проверять повторным измерением без профайлера.
Профилирование появилось как практический способ находить реальные узкие места вместо оптимизации кода по предположениям. Детерминированный профайлер наблюдает события выполнения и строит подробную статистику по функциям, что удобно для анализа структуры вызовов и разделения собственного времени функции от времени её потомков.
Цена такой детализации — дополнительная работа во время выполнения. Профайлер должен обработать событие, определить функцию, обновить счётчики и сохранить результаты, тогда как обычный запуск этого не делает.
Если сравнить обычный запуск с запуском под cProfile, второй может оказаться существенно медленнее даже при неизменном алгоритме. Ошибка возникает, когда эту разницу принимают за доказательство того, что функция сама плохо оптимизирована.
Искажение особенно опасно для небольших функций, глубоких цепочек вызовов и кода, где основная работа состоит из множества быстрых операций. Профилирование также может изменить поведение многопоточного приложения из-за дополнительной нагрузки и повлиять на взаимодействие потоков с планировщиком.
При детерминированном профилировании обработчик вызывается на событиях выполнения, прежде всего при входе в функции и выходе из них. Он фиксирует количество вызовов, время и связи между вызывающими и вызываемыми функциями; эти действия добавляются к работе программы.
Для функции с долгим вычислением стоимость профайлера может быть небольшой долей общего времени. Для функции, которая вызывается миллионы раз и выполняется за короткое время, накладной расход на каждый вызов становится значительной частью измеренного результата.
Из этого следуют два разных режима измерений:
Нельзя корректно вычислять ускорение по формуле «время под профайлером до оптимизации против времени без профайлера после оптимизации». Для сравнения нужно сохранять одинаковые входные данные, прогрев, окружение и число повторов, а измерять обе версии без профайлера.
Если подробность cProfile не нужна, для поиска горячих участков применяют статистическое профилирование: оно периодически снимает состояние стека, а не обрабатывает каждый вызов. Такой метод обычно вносит меньший накладной расход, но может не увидеть очень короткие функции и даёт вероятностную, а не полную картину.
В сервисе после рефакторинга разработчик увидел, что новая версия обрабатывает запросы медленнее под cProfile, и решил откатить изменение. Анализ показал, что рефакторинг увеличил число вызовов небольших вспомогательных функций, поэтому дополнительная стоимость обработки событий профайлера выросла сильнее, чем стоимость самого рабочего кода.
Рассматривались три варианта. Оставить вывод cProfile единственным критерием было быстро, но методологически неверно. Перейти только на журналирование отдельных участков давало малый overhead, однако не показывало полный граф вызовов. Использовать статистический профайлер было удобно для общей картины, но он мог пропустить кратковременные горячие функции.
Выбрали комбинированный подход: cProfile использовали для локализации подозрительных функций, затем сравнили версии на одинаковом наборе запросов без профайлера и отдельно проверили задержки в рабочем окружении. В результате стало ясно, какие изменения действительно ускоряют обработку, а какие лишь уменьшают или увеличивают искажение, создаваемое способом измерения.
Можно ли сравнивать абсолютное время функции из отчёта cProfile с пользовательской задержкой в production?
Нет, такое сравнение обычно некорректно. В отчёте отражается выполнение в инструментированном режиме, а пользовательская задержка включает накладные расходы сервера, планировщика, ввода-вывода, сериализации и других компонентов. Данные cProfile полезны для распределения времени внутри процесса, но абсолютную задержку нужно проверять отдельным измерением в условиях, близких к production.
Почему профайлер сильнее искажает результат для многих коротких функций, чем для одной долгой?
Стоимость обработки событий приблизительно добавляется к каждому наблюдаемому вызову. Если функция выполняется долго, эта добавка мала относительно её полезной работы; если функция очень короткая, она может быть сопоставима с ней или превысить её. Поэтому профиль способен изменить относительный рейтинг мелких функций и создать впечатление, что частые вызовы дороже, чем они есть в обычном запуске.
Как проверить, что найденная профайлером оптимизация действительно улучшила программу?
Сначала профайлером находят участок, на который стоит направить внимание. Затем выполняют несколько повторов исходной и изменённой версии без профайлера, используя одинаковые данные, настройки и схему прогрева, после чего сравнивают устойчивые статистики, а не один запуск.
Если приложение многопоточное или чувствительно к задержкам, дополнительно проверяют его в реалистичной среде и смотрят распределение задержек, а не только среднее время. После оптимизации полезно снова построить профиль: это подтверждает, что первоначальное узкое место исчезло, а стоимость не переместилась в другую часть программы.