如何進行 Python性能分析，你才能如魚得水？

【編者按】本文做者爲 Bryan Helmig，主要介紹 Python 應用性能分析的三種進階方案。文章系國內 ITOM 管理平臺 OneAPM 編譯呈現。

咱們應該忽略一些微小的效率提高，幾乎在 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 官方技術博客。

本文轉自 OneAPM 官方博客

原文地址：https://zapier.com/engineering/profiling-python-boss/