使用line_profiler查看api接口函数每行代码执行时间

项目情景描述

  在restful架构风格的项目交付测试的过程中,某接口出现 请求超时导致的http 502 Bad Gateway,于是开始排查具体是接口函数中的哪行代码或函数 响应时间过长导致的502错误

刚开始的解决方法:

  土鳖式的导入 time模块进行时间计算,从而查出具体响应时间过长的位置

  如下:

 import time import time
from flask import Flask
app = Flask(__name__) app.route('/line_test')
def line_test():
#土鳖方法
first_time=time()
for item in range(5):
time.sleep(1)
#土鳖方法
print time()-first_time
for item in xrange(5):
time.sleep(0.5)
#土鳖方法
print time()-first_time

  方法缺点:需要大量时间编写 关于 time()的代码,最后还要删除这些代码,浪费时间

现在的解决方法:

  使用python的 line_profiler 模块,此模块是用来测试 函数 每行代码的响应时间等情况

  具体思路:将 line_profiler相关函数封装在装饰器 中 进行使用,这样 在接口请求时,则会执行此装饰器并打印出结果

  windows安装方法:https://www.lfd.uci.edu/~gohlke/pythonlibs/#line_profiler

  代码如下:

 #coding:utf8
from flask import Flask, jsonify
import time
from functools import wraps
from line_profiler import LineProfiler #查询接口中每行代码执行的时间
def func_line_time(f):
@wraps(f)
def decorator(*args, **kwargs):
func_return = f(*args, **kwargs)
lp = LineProfiler()
lp_wrap = lp(f)
lp_wrap(*args, **kwargs)
lp.print_stats()
return func_return
return decorator
18 app = Flask(__name__) @app.route('/line_test')
@func_line_time
def line_test():
for item in range(5):
time.sleep(1)
for item in xrange(5):
time.sleep(0.5)
return jsonify({'code':200}) if __name__=='__main__':
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的使用方法:

在脚本中使用此方法:

 #coding:utf8
import cgi
import time
from line_profiler import LineProfiler def test2():
print 'hello!test2()' def test1():
html='''<script>alert("you are a good boy!&I like you")</scrpit>'''
test2()
escape_html=cgi.escape(html)
for item in range(5):
time.sleep(1)
print escape_html

if __name__=='__main__':
lp=LineProfiler()
#同时显示函数每行所用时间和调用函数每行所用时间,加入add_function()
lp.add_function(test2)
lp_wrap=lp(test1)
#如果被测函数有入参,下面一行为 lp_wrap(被测函数入参)
lp_wrap()
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.****.net/guofangxiandaihua/article/details/77825524

  

上一篇:NOIP前刷题记录


下一篇:NOIP刷题