python性能优化之函数执行时间分析_python性能优化之函数执行时间分析
最近發現項目API請求比較慢,通過抓包發現主要是response時間太長,于是就開始進行優化工作。優化工作的關鍵一步是定位出問題的瓶頸,對于優化速度來說,從優化函數執行時間這個維度去切入是一個不錯的選擇。
本文側重分析,不展開如何優化
利器
工欲善其事,必先利其器,我們需要一套方便高效的工具記錄函數運行時間。說是一套工具,但對于一個簡單項目或者日常開發來說,實現一個工具類足矣,由于實現比較簡單,直接上代碼:
from functools import wraps
import cProfile
from line_profiler import LineProfiler
import time
def func_time(f):
"""
簡單記錄執行時間
:param f:
:return:
"""
@wraps(f)
def wrapper(*args, **kwargs):
start = time.time()
result = f(*args, **kwargs)
end = time.time()
print f.__name__, 'took', end - start, 'seconds'
return result
return wrapper
def func_cprofile(f):
"""
內建分析器
"""
@wraps(f)
def wrapper(*args, **kwargs):
profile = cProfile.Profile()
try:
profile.enable()
result = f(*args, **kwargs)
profile.disable()
return result
finally:
profile.print_stats(sort='time')
return wrapper
try:
from line_profiler import LineProfiler
def func_line_time(follow=[]):
"""
每行代碼執行時間詳細報告
:param follow: 內部調用方法
:return:
"""
def decorate(func):
@wraps(func)
def profiled_func(*args, **kwargs):
try:
profiler = LineProfiler()
profiler.add_function(func)
for f in follow:
profiler.add_function(f)
profiler.enable_by_count()
return func(*args, **kwargs)
finally:
profiler.print_stats()
return profiled_func
return decorate
except ImportError:
def func_line_time(follow=[]):
"Helpful if you accidentally leave in production!"
def decorate(func):
@wraps(func)
def nothing(*args, **kwargs):
return func(*args, **kwargs)
return nothing
return decorate
原始代碼可以參考gist
如下,實現了3個裝飾器函數func_time,func_cprofile,func_line_time,分別對應
簡單輸出函數的執行時間
利用python自帶的內置分析包cProfile 分析,它主要統計函數調用以及每個函數所占的cpu時間
利用line_profiler開源項目,它可以統計每行代碼的執行次數和執行時間。
使用說明
我們以一個簡單的循環例子來說明一下,
def test():
for x in range(10000000):
print x
func_time
關于func_time我覺得沒什么好說的,就是簡單輸出下函數調用時間,這個在我們粗略統計函數執行時間的時候可以使用
如下:
@func_time
def test():
for x in range(10000000):
print x
# 輸出
test took 6.10190296173 seconds
func_cprofile
cProfile是python內置包,基于lsprof的用C語言實現的擴展應用,運行開銷比較合理,沒有外部依賴,適合做快速的概要測試
@func_cprofile
def test():
for x in range(10000000):
print x
# 輸出
3 function calls in 6.249 seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
1 6.022 6.022 6.249 6.249 test.py:41(test)
1 0.227 0.227 0.227 0.227 {range}
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
輸出說明:
單位為秒
第一行告訴我們一共有3個函數被調用。
正常開發過程,第一行更多是輸出類似194 function calls (189 primiive calls) in 0.249 seconds,(189 primiive calls)表示189個是原生(primitive)調用,表明這些調用不涉及遞歸
ncalls表示函數的調用次數,如果這一列有兩個數值,表示有遞歸調用,第一個是總調用次數,第二個是原生調用次數。
tottime是函數內部消耗的總時間(不包括調用其他函數的時間)。
percall是tottime除以ncalls,表示每次調用平均消耗時間。
cumtime是之前所有子函數消耗時間的累積和。
percall是cumtime除以原生調用的數量,表示該函數調用時,每個原生調用的平均消耗時間。
filename:lineno(function)為被分析函數所在文件名、行號、函數名。
func_line_time
line_profiler可以生成非常直接和詳細的報告,但它系統開銷很大,會比實際執行時間慢一個數量級
@func_line_time()
def test():
for x in range(10000000):
print x
# 輸出
Timer unit: 1e-06 s
Total time: 14.4183 s
File: /xx/test.py
Function: test at line 41
Line # Hits Time Per Hit % Time Line Contents
==============================================================
41 @func_line_time()
42 def test():
43 10000001 4031936.0 0.4 28.0 for x in range(10000000):
44 10000000 10386347.0 1.0 72.0 print x
輸出說明:
單位為微秒
Total Time:測試代碼的總運行時間
Line:代碼行號
Hits:表示每行代碼運行的次數
Time:每行代碼運行的總時間
Per Hits:每行代碼運行一次的時間
% Time:每行代碼運行時間的百分比
總結
日常開發中,可以使用func_time,func_cprofile做基本檢查,定位大致問題,使用func_line_time進行更細致的深入檢查。
注:func_line_time 還可以檢查函數內部調用的函數執行時間,通過follow參數指定對應的內部調用的函數聲明即可,該參數是個數組,也就是說可以檢查多個內部調用的函數
總結
以上是生活随笔為你收集整理的python性能优化之函数执行时间分析_python性能优化之函数执行时间分析的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: iap如何初始化_IAP超级详解
- 下一篇: jsp stc_为什么说jsp的本质是s