使用line_profiler查看api接口函数每行代码执行时间
使用line_profiler查看api接口函数每行代码执行时间
项目情景描述：
在restful架构风格的项目交付测试的过程中，某接口出现 请求超时导致的http 502 Bad Gateway，于是开始排查具体是接口函数中的哪行代码或函数 响应时间过长导致的502错误。
刚开始的解决方法：
土鳖式的导入 time模块进行时间计算，从而查出具体响应时间过长的位置
如下：
1 import time import time
2 from flask import Flask
3 app = Flask(__name__)
4
5 app.route('/line_test')
6 def line_test():
7 #土鳖方法
8 first_time=time()
9 for item in range(5):
10 time.sleep(1)
11 #土鳖方法
12 print time()-first_time
13 for item in xrange(5):
14 time.sleep(0.5)
15 #土鳖方法
16 print time()-first_time方法缺点：需要大量时间编写 关于 time()的代码，最后还要删除这些代码，浪费时间
现在的解决方法：
使用python的 line_profiler 模块，此模块是用来测试 函数 每行代码的响应时间等情况。
具体思路：将 line_profiler相关函数封装在装饰器 中 进行使用，这样 在接口请求时，则会执行此装饰器并打印出结果。
代码如下：
1 #coding:utf8
2 from flask import Flask, jsonify
3 import time
4 from functools import wraps
5 from line_profiler import LineProfiler
6
7 #查询接口中每行代码执行的时间
8 def func_line_time(f):
9 @wraps(f)
10 def decorator(*args, **kwargs):
11 func_return = f(*args, **kwargs)
12 lp = LineProfiler()
13 lp_wrap = lp(f)
14 lp_wrap()
15 lp.print_stats()
16 return func_return
17 return decorator
18
19
20 app = Flask(__name__)
21
22 @app.route('/line_test')
23 @func_line_time
24 def line_test():
25 for item in range(5):
26 time.sleep(1)
27 for item in xrange(5):
28 time.sleep(0.5)
29 return jsonify({'code':200})
30
31 if __name__=='__main__':
32 app.run()当浏览器请求接口时得到的结果如下：
* Running on http://127.0.0.1:5000/
Timer unit: 1e-06 s
Total time: 7.50827 s
File: /home/rgc/baidu_eye/carrier/test/flask_line_profiler_test.py
Function: line_test at line 22
Line # Hits Time Per Hit % Time Line Contents
==============================================================
22 @app.route('/line_test')
23 @func_line_time
24 def line_test():
25 6 33.0 5.5 0.0 for item in range(5):
26 5 5005225.0 1001045.0 66.7 time.sleep(1)
27 6 31.0 5.2 0.0 for item in xrange(5):
28 5 2502696.0 500539.2 33.3 time.sleep(0.5)
29 1 282.0 282.0 0.0 return jsonify({'code':200})
127.0.0.1 - - [05/Mar/2018 15:58:21] "GET /line_test HTTP/1.1" 200 -返回结果中 具体 含义：
Total Time：测试代码的总运行时间
Line:代码行号 Hits：表示每行代码运行的次数 Time：每行代码运行的总时间 Per Hits：每行代码运行一次的时间 % Time：每行代码运行时间的百分比
从 中便可看到 具体 26行代码执行时间最长。
方法优点：只需要添加一个装饰器，再接口函数前引用即可，删除也容易，且 装饰器可以重复使用，节省大量时间。
其他关于line_profiler的使用方法：
在脚本中使用此方法：
1 #coding:utf8
2 import cgi
3 import time
4 from line_profiler import LineProfiler
5
6 def test2():
7 print 'hello!test2()'
8
9 def test1():
10 html='''<script>alert("you are a good boy!&I like you")</scrpit>'''
11 test2()
12 escape_html=cgi.escape(html)
13 for item in range(5):
14 time.sleep(1)
15 print escape_html
16
17 if __name__=='__main__':
18 lp=LineProfiler()
19 #同时显示函数每行所用时间和调用函数每行所用时间，加入add_function()
20 lp.add_function(test2)
21 lp_wrap=lp(test1)
22 lp_wrap()
23 lp.print_stats()直接运行显示结果：
* Running on http://127.0.0.1:5000/
Timer unit: 1e-06 s
Total time: 7.50827 s
File: /home/rgc/baidu_eye/carrier/test/flask_line_profiler_test.py
Function: line_test at line 22
Line # Hits Time Per Hit % Time Line Contents
==============================================================
22 @app.route('/line_test')
23 @func_line_time
24 def line_test():
25 6 33.0 5.5 0.0 for item in range(5):
26 5 5005225.0 1001045.0 66.7 time.sleep(1)
27 6 31.0 5.2 0.0 for item in xrange(5):
28 5 2502696.0 500539.2 33.3 time.sleep(0.5)
29 1 282.0 282.0 0.0 return jsonify({'code':200})
127.0.0.1 - - [05/Mar/2018 15:58:21] "GET /line_test HTTP/1.1" 200 -相对于另一种使用方法：
1.在需要测试的函数前添加装饰器 @profile
2.启动程序 $kernprof -l -v test.py
无需 实际运行项目时删除@profile,如需单独测试此函数，直接使用 if __name__=='__main__': 即可，这样在其他函数引用时，不会执行line_profiler相关代码。
相关博客：
http://blog.csdn.net/guofangxiandaihua/article/details/77825524