如何进行 Python性能分析，你才能如鱼得水？（如何进行电子签名）

如何进行 Python性能分析，你才能如鱼得水？（如何进行电子签名）

我们应该忽略一些微小的效率提升，几乎在 97% 的情况下，都是如此：过早的优化是万恶之源。—— Donald Knuth

如果不先想想Knuth的这句名言，就开始进行优化工作，是不明智的。然而，有时你为了获得某些特性不假思索就写下了O(N^2) 这样的代码，虽然你很快就忘记它们了，它们却可能反咬你一口，给你带来麻烦：本文就是为这种情况而准备的。

本文会介绍用于快速分析Python程序的一些有用工具和模式。主要目标很简单：尽快发现问题，修复问题，并确认修复是行之有效的。

编写一个测试

在教程开始前，要先写一个简单的概要测试来演示延迟。你可能需要引入一些最小数据集来重现可观的延迟。通常一或两秒的运行时间，已经足够在发现问题时，让你做出改进了。

此外，进行一些基础测试来确保你的优化不会修改缓慢代码的行为也是有必要的。在分析和调整时，你也可以多次运行这些测试，作为基准。

那么现在，我们来看第一个分析工具。

简单的计时器

计时器是简单、灵活的记录执行时间的方法。你可以把它放到任何地方，并且几乎没有副作用。自己创建计时器非常简单，并且可以根据你的喜好定制化。例如，一个简单的计时器可以这么写：

import timedef timefunc(f):      def f_timer(*args, **kwargs):        start = time.time()        result = f(*args, **kwargs)        end = time.time()                print f.__name__, 'took', end - start, 'time'                return result         return f_timer     def get_number():      for x in xrange(5000000):              yield x@timefuncdef expensive_function():       for x in get_number():        i = x ^ x ^ x       return 'some result!'# prints "expensive_function took 0.72583088875 seconds"result = expensive_function()

当然，你可以用上下文管理器来增强它的功能，添加一些检查点或其他小功能：

import timeclass timewith():       def __init__(self, name=''):        self.name = name        self.start = time.time()               @property       def elapsed(self):             return time.time() - self.start            def checkpoint(self, name=''):              print '{timer} {checkpoint} took {elapsed} seconds'.format(            timer=self.name,            checkpoint=name,            elapsed=self.elapsed,        ).strip()                def __enter__(self):               return self               def __exit__(self, type, value, traceback):        self.checkpoint('finished')                pass        def get_number():       for x in xrange(5000000):              yield x      def expensive_function():       for x in get_number():        i = x ^ x ^ x        return 'some result!'    # prints something like:# fancy thing done with something took 0.582462072372 seconds# fancy thing done with something else took 1.75355315208 seconds# fancy thing finished took 1.7535982132 secondswith timewith('fancy thing') as timer:    expensive_function()    timer.checkpoint('done with something')    expensive_function()    expensive_function()    timer.checkpoint('done with something else')    # or directlytimer = timewith('fancy thing')expensive_function()timer.checkpoint('done with something')

有了计时器，你还需要进行一些“挖掘”工作。 封装一些更为高级的函数，然后确定问题根源之所在，进而深入可疑的函数，不断重复。当你发现运行特别缓慢的代码之后，修复它，然后进行测试以确认修复成功。

计时器的优点：容易理解和实施，也非常容易在修改前后进行对比，对于很多语言都适用。计时器的缺点：有时候，对于非常复杂的代码库而已太过简单，你可能会花更多的时间创建、替换样板代码，而不是修复问题！

内建分析器

内建分析器就好像大型枪械。虽然非常强大，但是有点不太好用，有时，解释和操作起来比较困难。

import cProfiledef do_cprofile(func):      def profiled_func(*args, **kwargs):        profile = cProfile.Profile()                try:            profile.enable()            result = func(*args, **kwargs)            profile.disable()                        return result                    finally:            profile.print_stats()            return profiled_func        def get_number():       for x in xrange(5000000):                yield x      @do_cprofiledef expensive_function():       for x in get_number():        i = x ^ x ^ x       return 'some result!'   # perform profilingresult = expensive_function()

在上面代码中，控制台打印的内容如下：

5000003 function calls in 1.626 seconds   Ordered by: standard name      ncalls  tottime  percall  cumtime  percall filename:lineno(function)     5000001    0.571    0.000    0.571    0.000 timers.py:92(get_number)           1    1.055    1.055    1.626    1.626 timers.py:96(expensive_function)           1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

如你所见，它给出了不同函数调用的详细数据。但是，它遗漏了一项关键信息：是什么原因，导致函数运行如此缓慢？

然而，这对于基础分析来说是个好的开端。有时，能够帮你尽快找到解决方案。我经常在开始调试过程时，把它作为基本测试，然后再深入测试某个不是运行缓慢，就是调用频繁的特定函数。

内建分析器的优点：没有外部依赖，运行非常快。对于快速的概要测试非常有用。内建分析器的缺点：信息相对有限，需要进一步的调试；报告不太直观，尤其是对于复杂的代码库。

Line Profiler

如果内建分析器是大型枪械，line profiler就好比是离子炮。它非常的重量级且强大，使用起来也非常有趣。

try:       from line_profiler import LineProfiler          def do_profile(follow=[]):              def inner(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 inner       except ImportError:      def do_profile(follow=[]):            "Helpful if you accidentally leave in production!"            def inner(func):                   def nothing(*args, **kwargs):                          return func(*args, **kwargs)                   return nothing             return inner     def get_number():       for x in xrange(5000000):             yield x          @do_profile(follow=[get_number])def expensive_function():       for x in get_number():        i = x ^ x ^ x       return 'some result!'result = expensive_function()

如果运行上面的代码，就会看到以下的报告：

Timer unit: 1e-06 sFile: test.pyFunction: get_number at line 43Total time: 4.44195 sLine #      Hits         Time  Per Hit   % Time  Line Contents==============================================================    43                                           def get_number():    44   5000001      2223313      0.4     50.1      for x in xrange(5000000):    45   5000000      2218638      0.4     49.9          yield xFile: test.pyFunction: expensive_function at line 47Total time: 16.828 sLine #      Hits         Time  Per Hit   % Time  Line Contents==============================================================    47                                           def expensive_function():    48   5000001     14090530      2.8     83.7      for x in get_number():    49   5000000      2737480      0.5     16.3          i = x ^ x ^ x    50         1            0      0.0      0.0      return 'some result!'

如你所见，这是一个非常详细的报告，能让你完全洞悉代码的运行情况。和内建的cProfiler不同，它能分析核心语言特性的耗时，比如循环或导入，并且给出不同代码行的耗时累计值。

这些细节能让我们更容易理解函数内部原理。 此外，如果需要研究第三方库，你可以将其导入，直接输到装饰器中。

提示：将测试函数封装为装饰器，再将问题函数作为参数传进去就好了！

Line Profiler 的优点：有非常直接和详细的报告。能够追踪第三方库里的函数。Line Profiler 的缺点：因为系统开销巨大，会比实际执行时间慢一个数量级，所以不要用它进行基准测试。同时，它是外部工具。

结论和最佳方案

你应该使用简单的工具（比如计时器或内建分析器）对测试用例（特别是那些你非常熟悉的代码）进行基本检查，然后使用更慢但更加细致的工具，比如 line_profiler，深入检查函数内部。

十有八九，你会发现一个愚蠢的错误，比如在循环内重复调用，或是使用了错误的数据结构，消耗了90%的函数执行时间。在进行快速（且令人满意的）调整之后，问题就能得到解决。

如果你仍然觉得程序运行太过缓慢，然后开始进行对比属性访问(ttribute accessing)方法，或调整相等检查(equality checking)方法等晦涩的调整，你可能已经适得其反了。你应该考虑如下方法：

注意，优化代码会带来有罪恶感的快乐！寻找加速Python的合理方法很有趣，但是不要因为加速，破坏了本身的逻辑。易读的代码比运行速度更重要。实施缓存，往往是最简单的解决方法。

教程到此为止，希望你今后的Python性能分析能够如鱼得水！