zlukfo@gmail.com

Python: Профилирование скриптов. Анализ скорости выполнения

Задача публикации - рассмотреть некоторые средства профилирования для скриптов python. В качестве примера будем анализировать такую функцию

def regex(c=None, r=True):
        if not r:
                res=re.findall('абр', s)
                return res
        if not c:
                res=re.findall(r'а[бв]+р', s)
                return res
        res=c.findall(s)
        return res

Общее время выполнения работы скрипта

Общее время можно оценить минимум двумя способами - средствами системы и средствами python

1. Оценка времени средствами системы

Создаем такой скрипт

if __name__=='__main__':
        s='абракадабра'
        for i in xrange(10000):
                regex()

и запускаем его

time python test.py

На выходе получаем

real 0m0.045s user 0m0.032s sys 0m0.012s

1. Оценка времени средствами python

Добавляем в скрипт небольшой класс

import time
class Timer(object):
    def __enter__(self):
        self.start = time.time()
        return self
    def __exit__(self, *args):
        self.end = time.time()
        self.secs = self.end - self.start

if __name__=='__main__':
        with Timer() as t:
                for i in xrange(10000):
                        regex()
        print "=> time: %s s" % t.secs

и запускаем скрипт. На выходе

=> time: 0.0494661331177 s

Разбираемся, что мы получили в первом и втором случаях

Но это, так сказать поверхностное тестирование - по результатам мы ничего не можем сказать о том сущесвует ли возможность сделать наш скрипт быстрее. Чтобы выяснить это - усланавливаем модуль профилировщика

pip install line_profiler

оборачиваем функцию regex() декоратором @profile и запускаем скрипт

if __name__=='__main__':
        s='абракадабра'
        for i in xrange(10000):
                regex()

kernprof -l -v test.py

Теперь у нас есть более информативный результат

  • общее время выполнения функции
  • сколько раз была выполнена каждая инструкция функции,
  • время выполнение инструкции при каждом вызове,
  • общее время выполнения каждой инструкции,
  • процент времени выполнения инструкции в общем времени выполнения функции

Теперь рассмотрим, как эту информацию можно использовать применительно к анализируемой функции. Как видно, функция regex() может быть вызвана тремя способами

  1. regex()- поиск подстроки будет выполняться по регурярному выражению
  2. regex(r=False) - поиск будет выполняться по строковой константе (без регулярного выражения)
  3. regex(p)- поиск выполняется по заранее скомпилированному шаблону

Оценим выполнение функции для каждого из вариантов. Поскольку regex() по сути состоит из одной функции re.findall(), будем также фиксировать и ее время работы (общее время работы функции / время выполнения re.findall())

  1. 0.172847 / 110148
  2. 0.136507 / 95330
  3. 0.100585 / 42084

Уже на данном этапе анализа можно сделать некоторые выводы

  • если искомая подстрока не содержит символы, идентифицирующие ее как регулярное выражение, то функция re.findall() выполняется быстрее (правда в данном случае для поиска подстроки она не нужна). Ктати, с увеличением количества обращений к функции разница в скорости выполнения междуд вариантами 1 и 2 будет сокращаться. По-видимому, это связано с тем, что функция findall (как и все остальные функции модуля re) сначала вызывает функцию compile, которая а) позволяет гораздо быстрее выполнять функции модуля и б) сохраняет 100 последних скомпилированных строк регулярного выражения, что позволяет избежать их повторной компиляции
  • при неоднократном вызове функций модуля re, шаблон регулярного выражения полезно предварительно компилировать. В варианте 3 эта операция была вынесена за пределы функции regex, что позволило увеличить общую скорость ее работы на 70%

Теперь подтвердим наши выводы. Для этого используем еще один инструмент профелирования cProfile. Выполним такой анализ скорости работы функции regex() для каждого из трех вариантов вызова

python -m cProfile -s time -o test1.prof test.py

Получим три файла профилирования. Анализировать их удобнее в графической оболочке kcachegrind.

sudo apt-get install kcachegrind

Кстати, для Windows есть порт программы https://sourceforge.net/projects/precompiledbin/

Для этого сначала сконвертируем их в нужный формат

sudo pip install pyprof2calltree
pyprof2calltree -i test1.prof -o test.kgrind

а затем откроем в графической оболочке

kcachegrind test.kgrind

Наши выводы подтверждаются - только в третьем варианте вызова функции regex() функция _compile вызывается только один раз. Во всех остальных - по количеству обращений к функции findall(). И именно эти излишние обращения увеличивают общее время работы скрипта

Опубликовано

Тема

Разработка

Ключевые слова