项目情景描述:
在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相关函数封装在装饰器 中 进行使用,这样 在接口请求时,则会执行此装饰器并打印出结果。
windows安装方法:https://www.lfd.uci.edu/~gohlke/pythonlibs/#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(*args, **kwargs)
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)
#如果被测函数有入参,下面一行为 lp_wrap(被测函数入参) 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