Python性能分析器 -- line_profiler

字数统计: 3.1k字 | 阅读时长: 15分

2021-06-15

摘要: 《Python性能分析与优化》关于 line_profiler 的笔记

【对算法，数学，计算机感兴趣的同学，欢迎关注我哈，阅读更多原创文章】
我的网站：潮汐朝夕的生活实验室
我的公众号：算法题刷刷
我的知乎：潮汐朝夕
我的github：FennelDumplings
我的leetcode：FennelDumplings

在文章Python性能分析基础中，我们学习了性能分析的基础知识方法论，如果把性能分析方法整合到开发过程中，就可以帮助我们提高产品的开发质量。

然后在文章 Python性能分析器 — cProfile 中，我们进一步学习了 cProfile 这个性能分析器。之后在文章使用cProfile进行性能分析与优化实践中，我们通过计算斐波那契数和读取大 csv 文件并做简单统计的两个例子进行了 cProfile 性能分析和优化的实践。

通过 cProfile 我们可以对代码进行性能分析,获取每个函数的调用次数和总调用次数。它帮助我们通过系统全局视角改进代码。

本文我们将学习另一种性能分析器,它可以为我们提供每一行代码的性能细节,这是cProfile无法提供的。

line_profiler

其他性能分析器主要关注函数调用消耗的CPU时间。大多数情况下,这足以发现问题,消除瓶颈(就像我们之前看到的那样)。但是,有时候,瓶颈问题发生在函数的某一行中,这时就需要line_profiler解决了。

line_profiler 安装

1	pip install line_profiler

line_profiler 的使用

(1) 直接使用 line_profiler

使用 line_profiler 进行性能分析,有两种方式可以获得函数的性能分析数据:用构造器或者用add_function方法。

line_profiler 和 cProfile.Profile 一样,也提供了下列方法。但是enable 和 disable在嵌入模块统计性能时并不安全,使用时要当心。

run
runctx
runcall
enable
disable

进行性能分析之后, 可以用dump_stats(filename)方法把stats加载到文件中。也可以用print_stats([stream])方法打印结果。它会把结果打印到sys.stdout里,或者任何其他设置成参数的数据流中。

import line_profiler
import sys

def test():
    for i in range(10):
        print(i ** 2)
    print("End of the function")

# pass in the function to profile
prof = line_profiler.LineProfiler(test) 

prof.enable() # start profiling
test()
prof.disable() # stop profiling

prof.print_stats(sys.stdout) # print out the results

profile 信息

Timer unit: 1e-06 s

Total time: 8.1e-05 s
File: test.py
Function: test at line 5

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     5                                           def test():
     6        11         10.0      0.9     12.3      for i in range(10):
     7        10         68.0      6.8     84.0          print(i ** 2)
     8         1          3.0      3.0      3.7      print("End of the function")

结果会显示函数的每一行，旁边是时间信息。共六列，出去代码行外的另外五列的含义如下

Line #: 表示文件中的行号。
Hits: 性能分析时一行代码的执行次数。
Time: 一行代码执行的总时间,由计时器的单位决定。在分析结果的最开始有一行Timer unit,该数值就是转换成秒的计时单位(要计算总时间,需要用Time数值乘以计时单位)。不同系统的计时单位可能不同。
Per hit: 执行一行代码的平均消耗时间,依然由系统的计时单位决定。
% Time: 执行一行代码的时间消耗占程序总消耗时间的比例。

(2) kernprof 工具

line_profiler 作者建议使用 kernprof 工具。kernprof 会创建一个性能分析器实例，并把名字添加到 __builtins__ 命名空间的 profile 中。

line_profiler 性能分析器被设计成一个装饰器，可以装饰任何一个函数，它会统计每一行消耗的时间。

kernprof 与 line_profiler 是集成在一起的。kernprof 将为我们做以下事情:

它将和cProfile、lsprof甚至profile模块一起工作,具体要看哪一个性能分析器可用。
它会自动寻找脚本文件,如果文件不在当前文件夹,它会检测PATH路径。
将实例化分析器,并把名字添加到builtins命名空间的profile中。这样我们就可以在代码中使用性能分析器了。我们甚至可以直接把它当作装饰器用,不需要导入。
stats性能分析文件的查看方式，下面的第二种和第三种注意后缀不一样
- 用pstats.Stats类
- python -m pstats stats_file.py.prof
- python -m line_profiler stats_file.py.lprof

例如: test.py 内容如下

import line_profiler

@profile
def fib(n):
    a, b = 0, 1
    for i in range(n):
        a, b = b, a + b
    return a

fib(int(1e5))

用以下命令执行性能分析器，被装饰的函数将被分析。

1	kernprof -l test.py

kernprof默认情况下会把分析结果写入test.py.lprof文件

可以用 -v 在命令行直接显示结果。

1	kernprof -l -v test.py

profile 结果如下

Wrote profile results to test2.py.lprof
Timer unit: 1e-06 s

Total time: 0.169616 s
File: test2.py
Function: fib at line 3

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     3                                           @profile
     4                                           def fib(n):
     5         1          1.0      1.0      0.0      a, b = 0, 1
     6    100001      31797.0      0.3     18.7      for i in range(n):
     7    100000     137817.0      1.4     81.3          a, b = b, a + b
     8         1          1.0      1.0      0.0      return a

在读取kernprof的输出结果时,有两件事情需要注意。

在性能分析函数调用另一个函数时,没有把每一行消耗的时间增加到总时间上:当完成一个函数的性能分析时,可能会发生之前的函数分析结果没有加到总时间上的情况。这是因为kernprof只记录函数内部消耗的时间,以免对程序造成额外的负担。
分析报告中,列表综合(list comprehension)表达式的Hit比它们实际消耗的要多很多:基本上是因为对表达式进行性能分析时,分析报告对每次迭代增加了一个Hit。

line_profiler 性能分析实例: 斐波那契数

在文章中使用cProfile进行性能分析与优化实践中我们用 cProfile 分析了斐波那契数的优化过程。共有原始的递归实现 fib，递归改迭代的实现 fib_seq，以及递归、迭代分别加上装饰器缓存。

这里用 line_profiler 对这四种实现进行分析，先分析不加装饰器缓存的递归和迭代实现。

import line_profiler

class cached:
    def __init__(self, fn):
        self.fn = fn
        self.cache = {}

    def __call__(self, *args):
        try:
            return self.cache[args]
        except KeyError:
            self.cache[args] = self.fn(*args)
            return self.cache[args]

@profile
def fib_iter(n):
    a, b = 0, 1
    for i in range(0, n):
        a, b = b, a+b
    return a

@profile
def fib(n):
    if n <= 1:
        return n
    else:
        return fib(n-1) + fib(n-2)

@profile
def fib_seq(n):
    seq = [ ]
    for i in range(0, n + 1):
        seq.append(fib(i))
    return seq

@profile
def fib_iter_seq(n):
    seq = [ ]
    for i in range(0, n + 1):
        seq.append(fib_iter(i))
    return seq

fib_seq(30)
fib_iter_seq(30)

性能分析器输出结果

Wrote profile results to fibo.py.lprof
Timer unit: 1e-06 s                                           
                                                              
Total time: 0.000282 s                                   
File: fibo.py                                                   
Function: fib_iter at line 15                                 
                                                                              
Line #      Hits         Time  Per Hit   % Time  Line Contents             
============================================================== 
    15                                           @profile
    16                                           def fib_iter(n):
    17        31         11.0      0.4      3.9      a, b = 0, 1
    18       496        135.0      0.3     47.9      for i in range(0, n):
    19       465        134.0      0.3     47.5          a, b = b, a+b
    20        31          2.0      0.1      0.7      return a 
                                                              
Total time: 5.93703 s                                    
File: fibo.py                                                        
Function: fib at line 22                                      
                                                                              
Line #      Hits         Time  Per Hit   % Time  Line Contents                  
============================================================== 
    22                                           @profile
    23                                           def fib(n):          
    24   7049123    2113346.0      0.3     35.6      if n <= 1:
    25   3524577     847516.0      0.2     14.3          return n
    26                                               else:
    27   3524546    2976165.0      0.8     50.1          return fib(n-1) + fib(n-2)

Total time: 16.4287 s
File: fibo.py
Function: fib_seq at line 29

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    29                                           @profile
    30                                           def fib_seq(n):
    31         1          1.0      1.0      0.0      seq = [ ]
    32        32         15.0      0.5      0.0      for i in range(0, n + 1):
    33        31   16428689.0 529957.7    100.0          seq.append(fib(i))
    34         1          1.0      1.0      0.0      return seq

Total time: 0.000567 s
File: fibo.py
Function: fib_iter_seq at line 36

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    36                                           @profile
    37                                           def fib_iter_seq(n):
    38         1          1.0      1.0      0.2      seq = [ ]
    39        32         10.0      0.3      1.8      for i in range(0, n + 1):
    40        31        555.0     17.9     97.9          seq.append(fib_iter(i))
    41         1          1.0      1.0      0.2      return seq

在fib函数里,没有一行代码消耗了太多时间也就是 Per-Hit 很小(，也不应该消耗很多时间)。在fib_seq里面,只有一行消耗了大量时间,但那是因为递归是在fib里面运行的。所以要解决的问题就是降低递归的次数。

在 fib_iter 和 fib 上均价上 cached 装饰器缓存。其余代码不变。

@cached
@profile
def fib_iter(n):
    a, b = 0, 1
    for i in range(0, n):
        a, b = b, a+b
    return a

@cached
@profile
def fib(n):
    if n <= 1:
        return n
    else:
        return fib(n-1) + fib(n-2)

性能分析器的结果如下

Wrote profile results to fibo.py.lprof
Timer unit: 1e-06 s         

Total time: 0.000295 s                                        
File: fibo.py                                                 
Function: fib_iter at line 15                            
                                                                
Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================                
    15                                           @cached                   
    16                                           @profile      
    17                                           def fib_iter(n):
    18        31          9.0      0.3      3.1      a, b = 0, 1
    19       496        120.0      0.2     40.7      for i in range(0, n):
    20       465        159.0      0.3     53.9          a, b = b, a+b
    21        31          7.0      0.2      2.4      return a
                                                              
Total time: 4.8e-05 s                                         
File: fibo.py                                            
Function: fib at line 23                                             
                                                              
Line #      Hits         Time  Per Hit   % Time  Line Contents                
==============================================================                  
    23                                           @cached       
    24                                           @profile                          
    25                                           def fib(n):
    26        31         10.0      0.3     20.8      if n <= 1:
    27         2          1.0      0.5      2.1          return n
    28                                               else:
    29        29         37.0      1.3     77.1          return fib(n-1) + fib(n-2)

Total time: 0.000157 s
File: fibo.py
Function: fib_seq at line 31

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    31                                           @profile
    32                                           def fib_seq(n):
    33         1          1.0      1.0      0.6      seq = [ ]
    34        32          9.0      0.3      5.7      for i in range(0, n + 1):
    35        31        147.0      4.7     93.6          seq.append(fib(i))
    36         1          0.0      0.0      0.0      return seq

Total time: 0.000656 s
File: fibo.py
Function: fib_iter_seq at line 38

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    38                                           @profile
    39                                           def fib_iter_seq(n):
    40         1          0.0      0.0      0.0      seq = [ ]
    41        32         10.0      0.3      1.5      for i in range(0, n + 1):
    42        31        646.0     20.8     98.5          seq.append(fib_iter(i))
    43         1          0.0      0.0      0.0      return seq

fib 的 Hit 数量大幅下降(7049123 -> 31)。

潮汐朝夕的生活实验室 \Doge 陪伴一个算法工程师的职业生涯

编程Python