Краткий ответ

Проверьте два показателя: tottime показывает время, проведённое непосредственно в теле функции, без учёта вызванных ею функций; cumtime — суммарное время функции вместе с дочерними вызовами. Если cumtime велик, а tottime мал, функция является дорогой в основном из-за вызываемой ею цепочки, а не из-за собственного кода.

Исторический контекст

Профилирование по стеку вызовов возникло из практической необходимости распределять общее время работы программы между функциями. Простого измерения длительности всей программы недостаточно: оно не показывает, какой участок кода отвечает за задержку.

cProfile собирает статистику вызовов и позволяет разделить собственное и накопленное время. Это помогает не оптимизировать оболочку функции, которая лишь запускает медленную операцию глубже в стеке.

Постановка проблемы

Рассмотрим функцию-координатор: она быстро проверяет параметры, формирует аргументы и вызывает несколько внутренних функций. В отчёте она может оказаться первой по cumtime, хотя её tottime почти нулевое.

Если ориентироваться только на cumtime, можно начать оптимизировать уже быстрый код координатора. Правильный вывод — найти дочерний вызов, который формирует большую часть накопленного времени, и проверить его собственный tottime или дальнейший стек.

Подробное решение

tottime — время, измеренное на текущем уровне вызова. Оно не включает время, проведённое в функциях, вызванных из этого уровня.

cumtime — накопленное время: собственное время функции плюс время всех вызовов ниже неё. Для функции, которая вызывает медленный запрос, сортировку или сериализацию, cumtime может быть большим даже при маленьком tottime.

Минимальный пример получения отчёта:

import cProfile
import pstats


def inner():
    sum(range(1_000_000))


def outer():
    inner()

profiler = cProfile.Profile()
profiler.enable()
outer()
profiler.disable()
pstats.Stats(profiler).sort_stats("cumulative").print_stats()

В отчёте у outer накопленное время будет близко ко времени inner, но её собственное время останется небольшим. Сортировка по cumulative удобна для поиска крупных ветвей вызовов, а сортировка по tottime — для поиска функций, где непосредственно выполняется дорогая работа.

При интерпретации важно учитывать число вызовов: небольшая стоимость одного вызова может стать существенной при миллионах повторений. Также профилировщик добавляет накладные расходы и измеряет конкретный сценарий, поэтому результаты следует сопоставлять с реальной нагрузкой.

Для рекурсивных функций статистика может быть менее очевидной: число примитивных и суммарных вызовов различается, а накопленное время включает вложенные уровни. Для многопроцессных приложений статистика каждого процесса обычно анализируется отдельно, если не настроено её явное объединение.

Ситуация из практики

В веб-сервисе обработчик запроса оказался лидером по cumtime. Команда сначала переписала его проверки и уменьшила tottime на несколько процентов, но задержка ответа почти не изменилась.

Рассматривались варианты:

оптимизировать тело обработчика — безопасно, но бесполезно, если его tottime мал;
сортировать отчёт только по tottime — помогает найти локально дорогие функции, но может скрыть важную ветвь вызовов;
изучить cumtime обработчика и спуститься по дочерним вызовам — позволяет найти фактический источник задержки, но требует анализа нескольких уровней стека.

Выбрали третий вариант. Оказалось, что основное время уходило в повторную сериализацию результата внутри вызываемой функции. После устранения лишней сериализации уменьшилось время ответа, тогда как оптимизация самого обработчика дала бы только незначительный эффект.

Что кандидаты часто упускают

Вопрос: Можно ли складывать cumtime всех функций, чтобы получить общее время выполнения?

Ответ: Обычно нельзя. Одно и то же время дочернего вызова входит в cumtime родительской функции и одновременно в cumtime самого дочернего вызова. Такое сложение многократно учитывает общие участки стека. Для оценки общего времени используют корневой вызов или отдельный замер всей операции.
Вопрос: Почему функция с маленьким временем одного вызова всё равно может быть целью оптимизации?

Ответ: Важна не только стоимость одного вызова, но и число вызовов. Функция, занимающая 10 микросекунд и вызываемая миллион раз, может дать около 10 секунд совокупной работы. Поэтому в отчёте нужно смотреть одновременно на число вызовов, tottime и cumtime, а оптимизацию проверять повторным измерением.
Вопрос: Всегда ли большое cumtime означает, что функция является причиной проблемы?

Ответ: Нет. Большое cumtime может быть естественным для верхнеуровневого обработчика, который охватывает почти всю операцию. Причиной обычно является конкретный дочерний участок с большим tottime, чрезмерным числом вызовов или неожиданно глубокой цепочкой. Поэтому cumtime используют для навигации по дереву вызовов, а окончательный объект оптимизации выбирают после анализа вложенных функций и проверки на рабочей нагрузке.