如何進行 Python性能分析,你才能如魚得水?
我們應該忽略一些微小的效率提升,幾乎在 97% 的情況下,都是如此:過早的優化是萬惡之源。—— Donald Knuth
如果不先想想Knuth的這句名言,就開始進行優化工作,是不明智的。然而,有時你為了獲得某些特性不假思索就寫下了O(N^2) 這樣的代碼,雖然你很快就忘記它們了,它們卻可能反咬你一口,給你帶來麻煩:本文就是為這種情況而準備的。
本文會介紹用于快速分析Python程序的一些有用工具和模式。主要目標很簡單: 盡快發現問題,修復問題,并確認修復是行之有效的 。
編寫一個測試
在教程開始前,要先寫一個簡單的概要測試來演示延遲。你可能需要引入一些最小數據集來重現可觀的延遲。通常一或兩秒的運行時間,已經足夠在發現問題時,讓你做出改進了。
此外,進行一些基礎測試來確保你的優化不會修改緩慢代碼的行為也是有必要的。在分析和調整時,你也可以多次運行這些測試,作為基準。
那么現在,我們來看第一個分析工具。
簡單的計時器
計時器是簡單、靈活的記錄執行時間的方法。你可以把它放到任何地方,并且幾乎沒有副作用。自己創建計時器非常簡單,并且可以根據你的喜好定制化。例如,一個簡單的計時器可以這么寫:
import time
def timefunc(f):
def f_timer(*args, **kwargs):
start = time.time()
result = f(*args, **kwargs)
end = time.time()
print f.__name__, 'took', end - start, 'time'
return result
return f_timer
def get_number():
for x in xrange(5000000):
yield x
@timefunc
def expensive_function():
for x in get_number():
i = x ^ x ^ x
return 'some result!'
# prints "expensive_function took 0.72583088875 seconds"
result = expensive_function()
當然,你可以用上下文管理器來增強它的功能,添加一些檢查點或其他小功能:
import time
class timewith():
def __init__(self, name=''):
self.name = name
self.start = time.time()
@property
def elapsed(self):
return time.time() - self.start
def checkpoint(self, name=''):
print '{timer} {checkpoint} took {elapsed} seconds'.format(
timer=self.name,
checkpoint=name,
elapsed=self.elapsed,
).strip()
def __enter__(self):
return self
def __exit__(self, type, value, traceback):
self.checkpoint('finished')
pass
def get_number():
for x in xrange(5000000):
yield x
def expensive_function():
for x in get_number():
i = x ^ x ^ x
return 'some result!'
# prints something like:
# fancy thing done with something took 0.582462072372 seconds
# fancy thing done with something else took 1.75355315208 seconds
# fancy thing finished took 1.7535982132 seconds
with timewith('fancy thing') as timer:
expensive_function()
timer.checkpoint('done with something')
expensive_function()
expensive_function()
timer.checkpoint('done with something else')
# or directly
timer = timewith('fancy thing')
expensive_function()
timer.checkpoint('done with something')
有了計時器,你還需要進行一些“挖掘”工作。 封裝一些更為高級的函數,然后確定問題根源之所在,進而深入可疑的函數,不斷重復。當你發現運行特別緩慢的代碼之后,修復它,然后進行測試以確認修復成功。
提示:不要忘了便捷的 timeit 模塊!將它用于小段代碼塊的基準校驗比實際測試更加有用。
-
計時器的優點:容易理解和實施,也非常容易在修改前后進行對比,對于很多語言都適用。
-
計時器的缺點:有時候,對于非常復雜的代碼庫而已太過簡單,你可能會花更多的時間創建、替換樣板代碼,而不是修復問題!
內建分析器
內建分析器就好像大型槍械。雖然非常強大,但是有點不太好用,有時,解釋和操作起來比較困難。
你可以 點此 閱讀更多關于內建分析模塊的內容,但是內建分析器的基本操作非常簡單:你啟用和禁用分析器,它能記錄所有的函數調用和執行時間。接著,它能為你編譯和打印輸出。一個簡單的分析器用例如下:
import cProfile
def do_cprofile(func):
def profiled_func(*args, **kwargs):
profile = cProfile.Profile()
try:
profile.enable()
result = func(*args, **kwargs)
profile.disable()
return result
finally:
profile.print_stats()
return profiled_func
def get_number():
for x in xrange(5000000):
yield x
@do_cprofile
def expensive_function():
for x in get_number():
i = x ^ x ^ x
return 'some result!'
# perform profiling
result = expensive_function()
在上面代碼中,控制臺打印的內容如下:
5000003 function calls in 1.626 seconds
Ordered by: standard name
ncalls tottime percall cumtime percall filename:lineno(function)
5000001 0.571 0.000 0.571 0.000 timers.py:92(get_number)
1 1.055 1.055 1.626 1.626 timers.py:96(expensive_function)
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
如你所見,它給出了不同函數調用的詳細數據。但是,它遺漏了一項關鍵信息:是什么原因,導致函數運行如此緩慢?
然而,這對于基礎分析來說是個好的開端。有時,能夠幫你盡快找到解決方案。我經常在開始調試過程時,把它作為基本測試,然后再深入測試某個不是運行緩慢,就是調用頻繁的特定函數。
-
內建分析器的優點:沒有外部依賴,運行非常快。對于快速的概要測試非常有用。
-
內建分析器的缺點:信息相對有限,需要進一步的調試;報告不太直觀,尤其是對于復雜的代碼庫。
Line Profiler
如果內建分析器是大型槍械,line profiler就好比是離子炮。它非常的重量級且強大,使用起來也非常有趣。
在這個例子里,我們會用非常棒的 kernprof line-profiler,作為 line_profiler PyPi包 。為了方便使用,我們會再次用裝飾器進行封裝,同時也可以防止我們把它留在生產代碼里(因為它比蝸牛還慢)。
try:
from line_profiler import LineProfiler
def do_profile(follow=[]):
def inner(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 inner
except ImportError:
def do_profile(follow=[]):
"Helpful if you accidentally leave in production!"
def inner(func):
def nothing(*args, **kwargs):
return func(*args, **kwargs)
return nothing
return inner
def get_number():
for x in xrange(5000000):
yield x
@do_profile(follow=[get_number])
def expensive_function():
for x in get_number():
i = x ^ x ^ x
return 'some result!'
result = expensive_function()
如果運行上面的代碼,就會看到以下的報告:
Timer unit: 1e-06 s
File: test.py
Function: get_number at line 43Total time: 4.44195 s
Line # Hits Time Per Hit % Time Line Contents
==============================================================
43 def get_number():
44 5000001 2223313 0.4 50.1 for x in xrange(5000000):
45 5000000 2218638 0.4 49.9 yield x
File: test.py
Function: expensive_function at line 47Total time: 16.828 s
Line # Hits Time Per Hit % Time Line Contents
==============================================================
47 def expensive_function():
48 5000001 14090530 2.8 83.7 for x in get_number():
49 5000000 2737480 0.5 16.3 i = x ^ x ^ x
50 1 0 0.0 0.0 return 'some result!'
如你所見,這是一個非常詳細的報告,能讓你完全洞悉代碼的運行情況。和內建的cProfiler不同,它能分析核心語言特性的耗時,比如循環或導入,并且給出不同代碼行的耗時累計值。
這些細節能讓我們更容易理解函數內部原理。 此外,如果需要研究第三方庫,你可以將其導入,直接輸到裝飾器中。
提示:將測試函數封裝為裝飾器,再將問題函數作為參數傳進去就好了!
-
Line Profiler 的優點:有非常直接和詳細的報告。能夠追蹤第三方庫里的函數。
-
Line Profiler 的缺點:因為系統開銷巨大,會比實際執行時間慢一個數量級,所以不要用它進行基準測試。同時,它是外部工具。
結論和最佳方案
你應該使用簡單的工具(比如計時器或內建分析器)對測試用例(特別是那些你非常熟悉的代碼)進行基本檢查,然后使用更慢但更加細致的工具,比如 line_profiler ,深入檢查函數內部。
十有八九,你會發現一個愚蠢的錯誤,比如在循環內重復調用,或是使用了錯誤的數據結構,消耗了90%的函數執行時間。在進行快速(且令人滿意的)調整之后,問題就能得到解決。
如果你仍然覺得程序運行太過緩慢,然后開始進行對比屬性訪問(ttribute accessing)方法,或調整相等檢查(equality checking)方法等晦澀的調整,你可能已經適得其反了。你應該考慮如下方法:
1.忍受緩慢或者預先計算/緩存
2.重新思考整個實施方法
3.使用更多的優化數據結構(通過 Numpy,Pandas等)
4.編寫一個 C擴展
注意,優化代碼會帶來有罪惡感的快樂!尋找加速Python的合理方法很有趣,但是不要因為加速,破壞了本身的邏輯。易讀的代碼比運行速度更重要。實施緩存,往往是最簡單的解決方法。
教程到此為止,希望你今后的Python性能分析能夠如魚得水!
PS: 點此 查看代碼實例。此外, 點此 學習如何如魚得水地調試 Python 程序。
OneAPM 能幫你查看Python 應用程序的方方面面,不僅能夠監控終端的用戶體驗,還能監控服務器性能,同時還支持追蹤數據庫、第三方 API 和 Web 服務器的各種問題。想閱讀更多技術文章,請訪問OneAPM 官方技術博客。
via: http://blog.oneapm.com/apm-tech/700.html