<jupyter_start><jupyter_text>高性能python-性能分析+ slug: high_performance_python_section1+ date: 2018-06-10 11:55+ modified: 2018-06-16+ category: Python+ tags: 性能分析+ author: timking+ summary: 对 &laquo;Python高性能分析&raquo; 的第二章的学习笔记, 简要描述了一些python中的性能分析手段。 这里是对 &laquo;Python高性能分析&raquo; 的文章解析。  将会引用来自书中的代码, 添加一些个人的理解备注, 作为学习笔记使用。> [引用代码](https://github.com/mynameisfiber/high_performance_python)  计算Julia集合<jupyter_code>import time 

x1, x2, y1, y2 = -1.8, 1.8, -1.8, 1.8 
c_real, c_imag = -0.62772, -.42193
def calculate_z_serial_purepython(maxiter, zs, cs):
    """Calculate output list using Julia update rule"""
    output = [0] * len(zs)
    for i in range(len(zs)):
        n = 0
        z = zs[i]
        c = cs[i]
        while abs(z) < 2 and n < maxiter:
            z = z * z + c
            n += 1
        output[i] = n
    return output
def calc_pure_python(desired_width, max_iterations):
    ''' 获取两个常数数组， x从x1 到 x2 均匀递增， y从y2 到 y1 均匀递减'''
    x_step = (float(x2 - x1) / float(desired_width))
    y_step = (float(y1 - y2) / float(desired_width))
    x = []
    y = []
    ycoord = y2
    while ycoord > y1:
        y.append(ycoord)
        ycoord += y_step
    xcoord = x1
    while xcoord < x2:
        x.append(xcoord)
        xcoord += x_step
    ''' 为图像中的每个格子构建一个复数值 '''
    zs = []
    cs = []
    for ycoord in y:
        for xcoord in x:
            zs.append(complex(xcoord, ycoord))
            cs.append(complex(c_real, c_imag))

    print("Length of x:", len(x))
    print("Total elements:", len(zs))
    start_time = time.time()
    output = calculate_z_serial_purepython(max_iterations, zs, cs)
    end_time = time.time()
    secs = end_time - start_time
    print(calculate_z_serial_purepython.__name__ + " took", secs, "seconds")

    # This sum is expected for a 1000^2 grid with 300 iterations.
    # It catches minor errors we might introduce when we're
    # working on a fixed set of inputs.
    assert sum(output) == 33219980
calc_pure_python(desired_width=1000, max_iterations=300)<jupyter_output>Length of x: 1000
Total elements: 1000000
calculate_z_serial_purepython took 8.289915800094604 seconds<jupyter_text>在以上这段代码中，可以看出函数的执行时间在 8s 左右。这里边有值得一提的是 我们可以通过装饰器构造一个方法来计算方法的执行时间。  就像下面这样。<jupyter_code>from functools import wraps

def timefn(fn):
    @wraps(fn)
    def measure_time(*args, **kwargs):
        t1 = time.time()
        result = fn(*args, **kwargs)
        t2 = time.time()
        print ("@timefn:" + fn.func_name + " took " + str(t2 - t1) + " seconds")
        return result
    return measure_time<jupyter_output><empty_output><jupyter_text>但不可避免的是，这样的方法总是要在源代码上添加一些代码，我们可以通过以下方法来获取一个函数的执行时间。  计算代码执行时长 我们可以通过几种办法获取一个函数的具体执行时长。* python代码使用 timeit 模块```shellpython -m timeit -n 5 -r 5 -s ""```这将会通过-n 执行循环次数, -r 指定重复次数，通过重复执行获取最好的结果 * unix 下使用 time 命令```bash/usr/bin/time -p python ""```这将会返回三个值， real 记录整体耗时， user 记录cpu在任务执行上消耗的时长， sys 记录cpu在调度过程内核函数消耗的时长> 这里可以通过添加参数 --verbose 获取更加详细的结果。  其中 `Major (requiring I/O) page faults` 指标表示 任务在磁盘IO上消耗的时长，这个值会造成 `user + sys = real` 的较大偏差 * ipython 下使用 %timeit 魔法命令> 这个命令和 python 的 timeit 模块效果是一致的，区别是需要在 ipython 环境下执行  使用cProfile模块 我们可以通过以下命令来调用cProfile模块获得代码中的每个函数的调用统计。  这其中包括 Ncalls 调用次数， cumtime 函数耗时时长， tottime 函数内部没有调用函数的其他代码的耗时时长。```shellpython -m cProfile -s cumulative -o profile.stats julia_nopil.py```> -s cumulative 对函数时间进行排序  -o 输出文件， 可以通过以下命令读取统计文件```pythonimport pstatsp = pstats.Stats("profile.stats")p.sort_stats("cumulative")p.print_stats()```  使用可视化工具对cProfile的输出进行可视化有时候查看cProfile的文件还是太过麻烦，这时就可以通过相应的可视化工具进行输出，这样更加直观方便。<jupyter_code>!python3 -m cProfile -s cumulative -o profile.stats julia_nopil.py<jupyter_output>Length of x: 1000
Total elements: 1000000
calculate_z_serial_purepython took 12.32185983657837 seconds<jupyter_text>使用gprof2dot对文件进行可视化分析使用前可以通过 `pip install gprof2dot` 来安装> [文档](https://github.com/jrfonseca/gprof2dot)gprof2dot可以将将多种Profiler的数据转成Graphviz可处理的图像表述。  配合dot命令，即可得到不同函数所消耗的时间分析图。<jupyter_code>!gprof2dot -f pstats profile.stats | dot -Tpng -o ../../../images/high-performance-python/section-2/profile.png<jupyter_output><empty_output><jupyter_text>得到下图. 从图中可以看出各个函数往下执行的调用占比。![profile.png]({filename}/images/high-performance-python/section-2/profile.png)  使用 vprof 进行可视化分析通过`pip install vprof`安装> [文档](https://github.com/nvdv/vprof)<jupyter_code>!vprof -c c julia_nopil.py # 这里将会执行启动一个web server，在浏览器上展示分析的结果<jupyter_output>Running FlameGraphProfiler...
Length of x: 1000
Total elements: 1000000
calculate_z_serial_purepython took 8.433602094650269 seconds
Starting HTTP server...<jupyter_text>RunSnakeRun```python TODO(timking): 补充RunSnakeRun的分析方法```这里还有一种方法可以使用，书中原文可以使用的这一种。但我暂时没有找到方法，暂时搁置。  使用LineProfiler进行逐行分析在上文我们找到耗时占比较大的函数之后。就可以通过 line_profile 来进行逐行分析。  使用 `pip install line_profiler`安装模块之后。  我们需要修改代码文件。在需要分析的函数处添加装饰器 `@profile`这里我们标记耗时较长的 calculate_z_serial_purepython 函数<jupyter_code>!kernprof -l -v julia_lineprofiler.py<jupyter_output>Length of x: 1000
Total elements: 1000000
calculate_z_serial_purepython took 92.4572069644928 seconds
Wrote profile results to julia_lineprofiler.py.lprof
Timer unit: 1e-06 s

Total time: 53.5594 s
File: julia_lineprofiler.py
Function: calculate_z_serial_purepython at line 7

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     7                                           @profile
     8                                           def calculate_z_serial_purepython(maxiter, zs, cs):
     9                                               """Calculate output list using Julia update rule"""
    10         1       4121.0   4121.0      0.0      output = [0] * len(zs)
    11   1000001     427083.0      0.4      0.8      for i in range(len(zs)):
    12   1000000     403721.0      0.4      0.8          n = 0
    13   1000000     479455.0      0.5      0.9          z = zs[i]
    14   1000000     446756.0      0.4      0.8  [...]<jupyter_text>从上面的输出看出，主要消耗时间集中在 while 循环中。  while判断 甚至两行赋值语句，都因为循环了 34219980次 而导致占比时间均在 30%左右。> while 判断中是两个表达式，无从判断两个表达式何者占用的时间更慢  但是通过推导可知，函数会比单纯的逻辑表达式更慢。  在while表达式之后，我们可以通过调整 两个表达式的先后顺序，使得第一次判断的时间减少  理论上将优化一定的性能，而书中的结果也印证了这一点> 在对整体对函数`calc_pure_python`分析中，引用书上的结果，  `calculate_z_serial_purepython`占用了97%的时间，可见创建列表的耗时在此次无足轻重  分析内存用量书上提到了使用memory_profiler 分析的方法，但是在实际生产环境中， memory_profiler会导致代码的执行效率急剧降低，这是不可忍受的。  好在我们可以通过Ipython的 `%memit` 来分析 某些语句的 RAM使用情况。  这些内容将会在后续章节中说明。  分析堆上的对象使用内存依照书上提供的 `guppy` 库好像无法在python3环境下工作。  只能退而求次使用另一个分析内存的工具 `objgraph`> [文档](https://mg.pov.lt/objgraph/)  单元测试<jupyter_code>!cat ex.py<jupyter_output>import unittest


@profile
def some_fn(nbr):
    return nbr * 2


class TestCase(unittest.TestCase):
    def test(self):
        result = some_fn(2)
        self.assertEquals(result, 4)<jupyter_text>对上述代码进行单元测试<jupyter_code>!nosetests ex.py<jupyter_output>.
----------------------------------------------------------------------
Ran 1 test in 0.000s

OK
{'fraction_non_alphanumeric': 0.12035962877030162, 'fraction_numerical': 0.048723897911832945, 'mean_word_length': 3.619557937039518, 'pattern_counts': {'":': 0, '<': 30, '<?xml version=': 0, '>': 37, 'https://': 4, 'lorem ipsum': 0, 'www.': 0, 'xml': 0}, 'pii_count': 0, 'substrings_counts': 0, 'word_list_counts': {'cursed_substrings.json': 6, 'profanity_word_list.json': 0, 'sexual_word_list.json': 0, 'zh_pornsignals.json': 0}}
{'chain_length': '8', 'dir': 'jupyter-structured-clean-dedup', 'id': '274637', 'license': 'MIT', 'n_tokens_mistral': 3504, 'n_tokens_neox': 3520, 'n_words': 525, 'path': 'content/books/high-performance-python/section-1/section-1.ipynb', 'repo_name': 'TimKingNF/timking.github.io', 'size': '6896'}