Анализ времени выполнения функции для оптимизации производительности Python

Python

Недавно было обнаружено, что запрос API проекта был относительно медленным, путем захвата пакетов было обнаружено, что время ответа слишком велико, поэтому начались работы по оптимизации. Ключевым этапом работы по оптимизации являетсяНайдите узкое место проблемы, для скорости оптимизации рекомендуется сократить время выполнения функции оптимизации.

Эта статья посвящена анализу, а не тому, как оптимизировать

острое оружие

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

from functools import wraps

import cProfile
from line_profiler import LineProfiler

import time


def func_time(f):
    """
    简单记录执行时间
    :param f:
    :return:
    """

    @wraps(f)
    def wrapper(*args, **kwargs):
        start = time.time()
        result = f(*args, **kwargs)
        end = time.time()
        print f.__name__, 'took', end - start, 'seconds'
        return result

    return wrapper


def func_cprofile(f):
    """
    内建分析器
    """

    @wraps(f)
    def wrapper(*args, **kwargs):
        profile = cProfile.Profile()
        try:
            profile.enable()
            result = f(*args, **kwargs)
            profile.disable()
            return result
        finally:
            profile.print_stats(sort='time')

    return wrapper



try:
    from line_profiler import LineProfiler


    def func_line_time(follow=[]):
        """
        每行代码执行时间详细报告
        :param follow: 内部调用方法
        :return:
        """
        def decorate(func):
            @wraps(func)
            def profiled_func(*args, **kwargs):
                try:
                    profiler = LineProfiler()
                    profiler.add_function(func)
                    for f in follow:
                        profiler.add_function(f)
                    profiler.enable_by_count()
                    return func(*args, **kwargs)
                finally:
                    profiler.print_stats()

            return profiled_func

        return decorate

except ImportError:
    def func_line_time(follow=[]):
        "Helpful if you accidentally leave in production!"
        def decorate(func):
            @wraps(func)
            def nothing(*args, **kwargs):
                return func(*args, **kwargs)

            return nothing

        return decorate

Исходный код может относиться кgist

Таким образом, реализованы три функции декоратора.func_time,func_cprofile,func_line_time, соответствующий

  1. Время выполнения простой функции вывода
  2. Используйте встроенный пакет анализа, который поставляется с Python.cProfileАнализ, который в основном подсчитывает вызовы функций и процессорное время, занимаемое каждой функцией.
  3. использоватьline_profilerПроект с открытым исходным кодом, он может подсчитывать время выполнения и время выполнения каждой строки кода.

Инструкции по применению

Давайте проиллюстрируем это на примере простого цикла,

def test():
    for x in range(10000000):
        print x
  • func_time

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

следующее:

@func_time
def test():
    for x in range(10000000):
        print x
# 输出
test took 6.10190296173 seconds
  • func_cprofile

cProfileЭто встроенный пакет Python, расширенное приложение, реализованное на языке C на основе lsprof, эксплуатационные расходы относительно разумны, нет внешней зависимости, и он подходит для быстрых итоговых тестов.

@func_cprofile
def test():
 for x in range(10000000):
     print x
# 输出
      3 function calls in 6.249 seconds

Ordered by: internal time

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1    6.022    6.022    6.249    6.249 test.py:41(test)
     1    0.227    0.227    0.227    0.227 {range}
     1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

Описание выхода:

в секундах

  1. Первая строка сообщает нам, что всего было вызвано 3 функции.

    Обычный процесс разработки, первая строка больше похожа на вывод194 function calls (189 primiive calls) in 0.249 seconds, (189 примитивных вызовов) указывает, что 189 являются примитивными вызовами, указывая на то, что эти вызовы не включают рекурсию

  2. ncalls представляет собой количество вызовов функции.Если в этом столбце два значения, это означает, что есть рекурсивные вызовы.Первое — общее количество вызовов, а второе — количество нативных вызовов.

  3. tottime — это общее время, проведенное внутри функции (исключая время, затраченное на вызов других функций).

  4. percall — это tottime, деленное на ncall, которое представляет собой среднее время, прошедшее за один вызов.

  5. cumtime — это кумулятивная сумма прошедшего времени всех предыдущих подфункций.

  6. percall — это cumtime, деленное на количество собственных вызовов, что означает среднее время использования каждого собственного вызова при вызове функции.

  7. filename:lineno(function) — это имя файла, номер строки и имя анализируемой функции.

  • func_line_time

line_profilerМожет генерировать очень прямые и подробные отчеты, но это очень дорого и будет на порядок медленнее, чем реальное время выполнения

@func_line_time()
def test():
    for x in range(10000000):
        print x
# 输出
Timer unit: 1e-06 s

Total time: 14.4183 s
File: /xx/test.py
Function: test at line 41

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    41                                           @func_line_time()
    42                                           def test():
    43  10000001    4031936.0      0.4     28.0      for x in range(10000000):
    44  10000000   10386347.0      1.0     72.0          print x

Описание выхода:

Единица измерения — микросекунды.

  1. Total Time: общее время работы тестового кода.

  2. Строка: номер строки кода

  3. Хиты: указывает, сколько раз запускалась каждая строка кода.

  4. Время: общее время выполнения каждой строки кода.

  5. Per Hits: время выполнения каждой строки кода один раз.

  6. % Time: процент времени, в течение которого выполнялась каждая строка кода.

Суммировать

В ежедневной разработке вы можете использоватьfunc_time,func_cprofileВыполняйте базовые проверки, определяйте общие проблемы, используйтеfunc_line_timeПроведите более тщательный осмотр.

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

Категории