使用cPython进行性能分析

station下的订单明细导出经常出现502超时。测试的时候发现在没有订单导出也特别慢，怀疑与数据量多少无关，肯定是某些操作特别耗时，为了找出具体位置，用了一下cProfile。

介绍性能分析器

profiler是一个程序，用来描述运行时的程序性能，并且从不同方面提供统计数据加以表述。Python中含有3个模块提供这样的功能，分别是cProfile, profile和pstats。这些分析器提供的是对Python程序的确定性分析。同时也提供一系列的报表生成工具，允许用户快速地检查分析结果。

Python标准库提供了3个不同的性能分析器：

cProfile，推荐给大部分的用户，是C的一个扩展应用，因为其合理的运行开销，所以适合分析运行时间较长的。是基于lsprof。
profile，一个纯python模块，它的接口和cProfile一致。在分析程序时，增加了很大的运行开销。如果你想扩展profiler的功能，可以试着继承这个模块。
hotshot, 一个试验性的c模块，关注减少分析时的运行开销，但是是以需要更长的数据后处理的次数为代价。不过这个模块不再被维护，也有可能在新的python版本中被弃用。

使用方法

def foo():
    sum = 0
    for i in range(10000):
        sum += i
    sumA = bar()
    sumB = bar()
    return sum
     
def bar():
    sum = 0
    for i in range(100000):
        sum += i
    return sum
  
if __name__ == "__main__":
    import cProfile
 
    #直接把分析结果打印到控制台
    cProfile.run("foo()")
    #把分析结果保存到文件中,不过内容可读性差...需要调用pstats模块分析结果
    cProfile.run("foo()", "result")
    #还可以直接使用命令行进行操作
    #>python -m cProfile myscript.py -o result
     
    import pstats
    #创建Stats对象
    p = pstats.Stats("result")
    #这一行的效果和直接运行cProfile.run("foo()")的显示效果是一样的
    p.strip_dirs().sort_stats(-1).print_stats()
    #strip_dirs():从所有模块名中去掉无关的路径信息
    #sort_stats():把打印信息按照标准的module/name/line字符串进行排序
    #print_stats():打印出所有分析信息
 
    #按照函数名排序 
    p.strip_dirs().sort_stats("name").print_stats()
 
    #按照在一个函数中累积的运行时间进行排序
    #print_stats(3):只打印前3行函数的信息,参数还可为小数,表示前百分之几的函数信息
    p.strip_dirs().sort_stats("cumulative").print_stats(3)
 
    #还有一种用法
    p.sort_stats('time', 'cum').print_stats(.5, 'foo')
    #先按time排序,再按cumulative时间排序,然后打倒出前50%中含有函数信息
 
    #如果想知道有哪些函数调用了bar,可使用
    p.print_callers(0.5, "bar")
 
    #同理,查看foo()函数中调用了哪些函数
    p.print_callees("foo")

以上是profile以及pstats模块的简单应用.

分析结果图解

分析结果

什么是确定性性能分析(Deterministic Profiling)

确定性性能分析指的是反映所有的函数调用，返回，和异常事件的执行所用的时间，以及它们之间的时间间隔。相比之下，统计性性能分析指的是取样有效的程序指令，然后推导出所需要的时间，后者花费比较少的开销，但是给出的结果不够精确。

在Python中，因为其是解释性语言，所以在执行程序的时候，会加入解释器的执行，这部分的执行是不需要进行性能分析的。Python自动为每一个事件提供一个hook，来定位需要分析的代码。除此之外，因为Python解释型语言的本质往往需要在执行程序的时候加入很多其它的开销，而确定性性能分析只会加入一点点处理开销。这样一来，确定性性能分析其实开销不大，还可以提供丰富的统计信息。

函数调用次数的统计能够被用于确定程序中的bug，比如一个不符合常理的次数，明显偏多之类的，还可以用来确定可能的内联函数。函数内部运行时间的统计可被用来确定”hot loops”，那些需要运行时间过长，需要优化的部分；累积时间的统计可被用来确定比较高层次的错误，比如算法选择上的错误。Python的性能分析可以允许直接比较算法的递归实现与迭代实现的。

实际应用

添加代码：

import cProfile
cProfile.runctx("self.get_order(request)", locals={'self':self, 'request':request}, globals={})

结果：

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:1000(__init__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:1019(init_module_attrs)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:1099(create)
        1    0.000    0.000    0.002    0.002 <frozen importlib._bootstrap>:1122(_exec)
        1    0.000    0.000    0.002    0.002 <frozen importlib._bootstrap>:1186(_load_unlocked)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:1266(find_spec)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:129(_new_module)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:1336(find_spec)
        1    0.000    0.000    0.002    0.002 <frozen importlib._bootstrap>:1465(exec_module)
        1    0.000    0.000    0.001    0.001 <frozen importlib._bootstrap>:1534(get_code)
        1    0.000    0.000  106.898  106.898 order.py:6(get_tmp_first)
        1    0.000    0.000    0.001    0.001 orderstatistics.py:248(get_orderDetail_in)
        1    0.000    0.000    0.000    0.000 orderstatistics.py:336(get_snap_sku_in)

结果发现get_tmp_first很耗时，优化下相关函数就好了

将分析结果保存在文件中查看

import cProfile
pr = cProfile.Profile()
pr.enable()
result = self.get_order(request) # 这里调用需要分析的代码
pr.disable()
pr.dump_stats('test.txt') # 保存到当前目录的下的test.txt文件

保存的文件不是纯文本，而且pstats.Stats对象的序列化数据，需要用pstats模块读取

import pstats
a = pstats.Stats('test.txt')
a.sort_stats('cumtime') # 按照累积时间排序
a.print_stats(50) # 输出50条数据
a.print_callees('get_order') # 输出get_order调用的函数的统计信息