Python 性能调试工具Line-profiler极简使用笔记

虽然Python屡屡被人诟病速度问题,但是该用的还得用,速度问题只能靠代码优化来解决了。Line-Profiler是一个代码优化工具,利用line—profiler我们可以得到我们每一行代码的运行总时间以及单次平均运行时间,以便我们对耗时最长的地方进行优化。

安装:

pip install line_profiler

1、极简模式

下面我们使用line-profiler查看一个简单实例各行代码时间都花在哪。

import random

def do_stuff():
    numbers = []
    for i in range(1000):
        numbers.append(random.randint(0,1000))
    s = sum(numbers)
    l = [numbers[i]/43 for i in range(len(numbers))]
    m = ['hello'+str(numbers[i]) for i in range(len(numbers))]
    return None
 

if __name__ == '__main__':
    from line_profiler import LineProfiler
    
    lp = LineProfiler()
    lp_wrapper = lp(do_stuff)
    lp_wrapper()
    lp.print_stats()

下面我们再命令行运行一下看看时间都去哪了:

$ root@cpu-k8ss-0 # python loader_test.py 
Timer unit: 1e-06 s

Total time: 0.0075 s
File: loader_test.py
Function: do_stuff at line 88

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    88                                           def do_stuff():
    89         1          1.0      1.0      0.0      numbers = []
    90      1001        697.0      0.7      9.3      for i in range(1000):
    91      1000       6093.0      6.1     81.2          numbers.append(random.randint(0,1000))
    92         1         10.0     10.0      0.1      s = sum(numbers)
    93         1        240.0    240.0      3.2      l = [numbers[i]/43 for i in range(len(numbers))]
    94         1        458.0    458.0      6.1      m = ['hello'+str(numbers[i]) for i in range(len(numbers))]
    95         1          1.0      1.0      0.0      return None

上面输出中,可以看到我们测试的函数为do_stuff, 起始于位于脚本的第88行。运行程序共花费时间0.0075 s。

紧接着的各列含义如下:

  • Line #, 对应脚本中的代码行数;
  • Hits,对应行共计运行次数;
  • Time,对应行运行总时间;
  • Per Hit,对应行平均每次运行时间;
  • % Time, 对应行运行时间占程序运行总时间的比例;
  • Line Contents,对应的每一行的代码内容。

从上面可以看到我们的时间主要花在了第一个生成数据的for循环中,共计占了90.5%,我们可以使用列表推导式来对其进行优化。

$ root@cpu-k8ss-0 # python loader_test.py 
Timer unit: 1e-06 s

Total time: 0.00503 s
File: loader_test.py
Function: do_stuff at line 88

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    88                                           def do_stuff():
    89                                               # numbers = []
    90                                               # for i in range(1000):
    91                                               # numbers.append(random.randint(0,1000))
    92         1       4434.0   4434.0     88.2      numbers = [random.randint(1,100) for i in range(1000)]
    93         1          8.0      8.0      0.2      s = sum(numbers)
    94         1        194.0    194.0      3.9      l = [numbers[i]/43 for i in range(len(numbers))]
    95         1        393.0    393.0      7.8      m = ['hello'+str(numbers[i]) for i in range(len(numbers))]
    96         1          1.0      1.0      0.0      return None

可以看到使用列表推导式后,我们的总时间减少了,生成数据这一步占程序总运行时间比例也降低了。

给函数传入参数

下面我们将numbers数据生成过程放到外面,以参数形式传入到函数中:

def do_stuff(numbers):
    # numbers = []
    # for i in range(1000):
    # numbers.append(random.randint(0,1000))
    #numbers = [random.randint(1,100) for i in range(1000)]
    s = sum(numbers)
    l = [numbers[i]/43 for i in range(len(numbers))]
    m = ['hello'+str(numbers[i]) for i in range(len(numbers))]
    return None

if __name__ == '__main__':
    from line_profiler import LineProfiler
    lp = LineProfiler()
    lp_wrapper = lp(do_stuff)
    # 生成参数并传入
    numbers = [random.randint(1,100) for i in range(100000)]
    lp_wrapper(numbers)
    lp.print_stats()

命令行运行:

$ root@cpu-k8ss-0 # python loader_test.py 
Timer unit: 1e-06 s

Total time: 0.084887 s
File: loader_test.py
Function: do_stuff at line 88

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    88                                           def do_stuff(numbers):
    89                                               # numbers = []
    90                                               # for i in range(1000):
    91                                               # numbers.append(random.randint(0,1000))
    92                                               #numbers = [random.randint(1,100) for i in range(1000)]
    93         1        788.0    788.0      0.9      s = sum(numbers)
    94         1      26504.0  26504.0     31.2      l = [numbers[i]/43 for i in range(len(numbers))]
    95         1      57593.0  57593.0     67.8      m = ['hello'+str(numbers[i]) for i in range(len(numbers))]
    96         1          2.0      2.0      0.0      return None

可以看到,现在程序运行的时间主要花在计算除数和连接字符串了。

显示内层调用函数的运行时间

在上面的例子中,我们将所有代码放在了一个函数中,只查看这个函数的代码的运行时间。line-profiler支持查看调用的函数内部运行时间。

def generate_numbers(n):
    numbers = [random.randint(1,100) for i in range(1000)]
    return numbers

 
def do_stuff(n):
    numbers = generate_numbers(n)
    s = sum(numbers)
    l = [numbers[i]/43 for i in range(len(numbers))]
    m = ['hello'+str(numbers[i]) for i in range(len(numbers))]
    return None

if __name__ == '__main__':
    from line_profiler import LineProfiler
    lp = LineProfiler()
    lp_wrapper = lp(do_stuff)
    # 加入并显示调用函数各行代码用时
    lp.add_function(generate_numbers)
    # 生成参数并传入
    n = 100000
    lp_wrapper(n)
    lp.print_stats()

命令行运行:

$ root@cpu-k8ss-0 # python loader_test.py 
Timer unit: 1e-06 s

Total time: 0.005112 s
File: loader_test.py
Function: generate_numbers at line 87

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    87                                           def generate_numbers(n):
    88         1       5111.0   5111.0    100.0      numbers = [random.randint(1,100) for i in range(1000)]
    89         1          1.0      1.0      0.0      return numbers

Total time: 0.005709 s
File: loader_test.py
Function: do_stuff at line 92

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    92                                           def do_stuff(n):
    93         1       5125.0   5125.0     89.8      numbers = generate_numbers(n)
    94         1          8.0      8.0      0.1      s = sum(numbers)
    95         1        189.0    189.0      3.3      l = [numbers[i]/43 for i in range(len(numbers))]
    96         1        387.0    387.0      6.8      m = ['hello'+str(numbers[i]) for i in range(len(numbers))]
    97         1          0.0      0.0      0.0      return None

在上面我们可以看到两个函数各行代码的运行时间,非常方便。

当然,line-profile还可以通过装饰器@profiler方式统计我们想要优化的函数。然后在命令行中通过命令$ kernprof -l script_to_profile.py来进行运行。

参考:
官方说明
使用line_profiler查看api接口函数每行代码执行时间
python 性能调试工具(line_profiler)使用

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 215,634评论 6 497
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 91,951评论 3 391
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 161,427评论 0 351
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 57,770评论 1 290
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 66,835评论 6 388
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,799评论 1 294
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,768评论 3 416
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,544评论 0 271
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,979评论 1 308
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,271评论 2 331
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,427评论 1 345
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,121评论 5 340
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,756评论 3 324
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,375评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,579评论 1 268
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 47,410评论 2 368
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,315评论 2 352

推荐阅读更多精彩内容