(轉)python性能檢測工具整理


python 運行后出現core dump產生core.**文件,可通過gdb來調試

Using GDB with a core dump

having found build/python/core.22608, we can now launch GDB:

gdb programname coredump
i.e.

gdb /usr/bin/python2 build/python/core.22608
A lot of information might scroll by.

At the end, you're greeted by the GDB prompt:

(gdb) 
Getting a backtrace

Typically, you'd just get a backtrace (or shorter, bt). A backtrace is simply the hierarchy of functions that were called.

 (gdb)bt
[...] skipped,

Frame #2 and following definitely look like they're part of the Python implementation -- that sounds bad, because GDB doesn't itself know how to debug python, but luckily, there's an extension to do that. So we can try to use py-bt:

(gdb) py-bt
If we get a undefined command error, we must stop here and make sure that the python development package is installed (python-devel on Redhatoids, python2.7-dev on Debianoids); for some systems, you should append the content of /usr/share/doc/{python-devel,python2.7-dev}/gdbinit[.gz] to your ~/.gdbinit, and re-start gdb.

The output of py-bt now states clearly which python lines correspond to which stack frame (skipping those stack frames that are hidden to python, because they are in external libraries or python-implementation routines)

...

 

 分析程序的性能可以歸結為回答四個基本問題:

  1. 正運行的多快

  2. 速度瓶頸在哪里

  3. 內存使用率是多少

  4. 內存泄露在哪里

用 time 粗粒度的計算時間

$ time python yourprogram.py
real    0m1.028s
user    0m0.001s
sys     0m0.003s

上面三個輸入變量的意義在文章 stackoverflow article 中有詳細介紹。簡單的說:

  • real - 表示實際的程序運行時間
  • user - 表示程序在用戶態的cpu總時間
  • sys - 表示在內核態的cpu總時間

通過sysuser時間的求和,你可以直觀的得到系統上沒有其他程序運行時你的程序運行所需要的CPU周期。

sysuser時間之和遠遠少於real時間,那么你可以猜測你的程序的主要性能問題很可能與IO等待相關。

使用計時上下文管理器進行細粒度計時

我們的下一個技術涉及訪問細粒度計時信息的直接代碼指令。這是一小段代碼,我發現使用專門的計時測量是非常重要的:

timer.py

import time
 
class Timer(object):
    def __init__(self, verbose=False):
        self.verbose = verbose
 
    def __enter__(self):
        self.start = time.time()
        return self
 
    def __exit__(self, *args):
        self.end = time.time()
        self.secs = self.end - self.start
        self.msecs = self.secs * 1000  # millisecs
        if self.verbose:
            print 'elapsed time: %f ms' % self.msecs

 為了使用它,使用 Python 的 with 關鍵字和 Timer 上下文管理器來包裝你想計算的代碼。當您的代碼塊開始執行,它將照顧啟動計時器,當你的代碼塊結束的時候,它將停止計時器。

這個代碼片段示例:

from timer import Timer
from redis import Redis
rdb = Redis()
 
with Timer() as t:
    rdb.lpush("foo", "bar")
print "=> elasped lpush: %s s" % t.secs
 
with Timer() as t:
    rdb.lpop("foo")
print "=> elasped lpop: %s s" % t.secs

我經常將這些計時器的輸出記錄到文件中,這樣就可以觀察我的程序的性能如何隨着時間進化。

使用分析器逐行統計時間和執行頻率

Robert Kern有一個稱作line_profiler的不錯的項目,我經常使用它查看我的腳步中每行代碼多快多頻繁的被執行。

想要使用它,你需要通過pip安裝該python包:

pip install line_profiler

安裝完成后,你將獲得一個新模塊稱為 line_profiler 和 kernprof.py 可執行腳本。

為了使用這個工具,首先在你想測量的函數上設置 @profile 修飾符。不用擔心,為了這個修飾符,你不需要引入任何東西。kernprof.py 腳本會在運行時自動注入你的腳本。

primes.py 

@profile
def primes(n): 
    if n==2:
        return [2]
    elif n<2:
        return []
    s=range(3,n+1,2)
    mroot = n ** 0.5
    half=(n+1)/2-1
    i=0
    m=3
    while m <= mroot:
        if s[i]:
            j=(m*m-3)/2
            s[j]=0
            while j<half:
                s[j]=0
                j+=m
        i=i+1
        m=2*i+3
    return [2]+[x for x in s if x]
primes(100)

一旦你得到了你的設置了修飾符 @profile 的代碼,使用 kernprof.py 運行這個腳本。

kernprof.py -l -v fib.py

-l 選項告訴 kernprof 把修飾符 @profile 注入你的腳本,-v 選項告訴 kernprof 一旦你的腳本完成后,展示計時信息。這是一個以上腳本的類似輸出:

Wrote profile results to primes.py.lprof
Timer unit: 1e-06 s
 
File: primes.py
Function: primes at line 2
Total time: 0.00019 s
 
Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     2                                           @profile
     3                                           def primes(n): 
     4         1            2      2.0      1.1      if n==2:
     5                                                   return [2]
     6         1            1      1.0      0.5      elif n<2:
     7                                                   return []
     8         1            4      4.0      2.1      s=range(3,n+1,2)
     9         1           10     10.0      5.3      mroot = n ** 0.5
    10         1            2      2.0      1.1      half=(n+1)/2-1
    11         1            1      1.0      0.5      i=0
    12         1            1      1.0      0.5      m=3
    13         5            7      1.4      3.7      while m <= mroot:
    14         4            4      1.0      2.1          if s[i]:
    15         3            4      1.3      2.1              j=(m*m-3)/2
    16         3            4      1.3      2.1              s[j]=0
    17        31           31      1.0     16.3              while j<half:
    18        28           28      1.0     14.7                  s[j]=0
    19        28           29      1.0     15.3                  j+=m
    20         4            4      1.0      2.1          i=i+1
    21         4            4      1.0      2.1          m=2*i+3
    22        50           54      1.1     28.4      return [2]+[x for x

尋找 hits 值比較高的行或是一個高時間間隔。這些地方有最大的優化改進空間。

程序使用了多少內存?

現在我們對計時有了較好的理解,那么讓我們繼續弄清楚程序使用了多少內存。我們很幸運,Fabian Pedregosa模仿Robert Kern的line_profiler實現了一個不錯的內存分析器

首先使用pip安裝:

$ pip install -U memory_profiler
$ pip install psutil

(這里建議安裝psutil包,因為它可以大大改善memory_profiler的性能)。

就像line_profiler,memory_profiler也需要在感興趣的函數上面裝飾@profile裝飾器:

@profile
def primes(n): 
    ...
    ...

運行如下命令來顯示你的函數使用了多少內存:

$ python -m memory_profiler primes.py

一旦你的程序退出,你應該可以看到這樣的輸出:

Filename: primes.py
 
Line #    Mem usage  Increment   Line Contents
==============================================
     2                           @profile
     3    7.9219 MB  0.0000 MB   def primes(n): 
     4    7.9219 MB  0.0000 MB       if n==2:
     5                                   return [2]
     6    7.9219 MB  0.0000 MB       elif n<2:
     7                                   return []
     8    7.9219 MB  0.0000 MB       s=range(3,n+1,2)
     9    7.9258 MB  0.0039 MB       mroot = n ** 0.5
    10    7.9258 MB  0.0000 MB       half=(n+1)/2-1
    11    7.9258 MB  0.0000 MB       i=0
    12    7.9258 MB  0.0000 MB       m=3
    13    7.9297 MB  0.0039 MB       while m <= mroot:
    14    7.9297 MB  0.0000 MB           if s[i]:
    15    7.9297 MB  0.0000 MB               j=(m*m-3)/2
    16    7.9258 MB -0.0039 MB               s[j]=0
    17    7.9297 MB  0.0039 MB               while j<half:
    18    7.9297 MB  0.0000 MB                   s[j]=0
    19    7.9297 MB  0.0000 MB                   j+=m
    20    7.9297 MB  0.0000 MB           i=i+1
    21    7.9297 MB  0.0000 MB           m=2*i+3
    22    7.9297 MB  0.0000 MB       return [2]+[x for x in s if x]

line_profiler和memory_profiler的IPython快捷方式

memory_profiler和line_profiler有一個鮮為人知的小竅門,兩者都有在IPython中的快捷命令。你需要做的就是在IPython會話中輸入以下內容:

%load_ext memory_profiler
 
%load_ext line_profiler

在這樣做的時候你需要訪問魔法命令%lprun和%mprun,它們的行為類似於他們的命令行形式。主要區別是你不需要使用@profiledecorator來修飾你要分析的函數。只需要在IPython會話中像先前一樣直接運行分析:

In [1]: from primes import primes
In [2]: %mprun -f primes primes(1000)
In [3]: %lprun -f primes primes(1000)

這可以節省你大量的時間和精力,因為使用這些分析命令,你不需要修改你的源代碼。

內存泄漏在哪里?

cPython解釋器使用引用計數做為記錄內存使用的主要方法。這意味着每個對象包含一個計數器,當某處對該對象的引用被存儲時計數器增加,當引用被刪除時計數器遞減。當計數器到達零時,cPython解釋器就知道該對象不再被使用,所以刪除對象,釋放占用的內存。

如果程序中不再被使用的對象的引用一直被占有,那么就經常發生內存泄漏。

查找這種“內存泄漏”最快的方式是使用Marius Gedminas編寫的objgraph,這是一個極好的工具。該工具允許你查看內存中對象的數量,定位含有該對象的引用的所有代碼的位置。

一開始,首先安裝objgraph:

pip install objgraph

一旦你已經安裝了這個工具,在你的代碼中插入一行聲明調用調試器:

import pdb; pdb.set_trace()
最普遍的對象是哪些?

在運行的時候,你可以通過執行下述指令查看程序中前20個最普遍的對象:

pdb) import objgraph
(pdb) objgraph.show_most_common_types()
 
MyBigFatObject             20000
tuple                      16938
function                   4310
dict                       2790
wrapper_descriptor         1181
builtin_function_or_method 934
weakref                    764
list                       634
method_descriptor          507
getset_descriptor          451
type                       439
哪些對象已經被添加或刪除?

我們也可以查看兩個時間點之間那些對象已經被添加或刪除:

(pdb) import objgraph
(pdb) objgraph.show_growth()
.
.
.
(pdb) objgraph.show_growth()   # this only shows objects that has been added or deleted since last show_growth() call
 
traceback                4        +2
KeyboardInterrupt        1        +1
frame                   24        +1
list                   667        +1
tuple                16969        +1
誰引用着泄漏的對象?

繼續,你還可以查看哪里包含給定對象的引用。讓我們以下述簡單的程序做為一個例子:

x = [1]
y = [x, [x], {"a":x}]
import pdb; pdb.set_trace()

為了看到持有變量 X 的引用是什么,運行 objgraph.show_backref() 函數:

(pdb) import objgraph
(pdb) objgraph.show_backref([x], filename="/tmp/backrefs.png")

該命令的輸出是一個 PNG 圖片,被存儲在 /tmp/backrefs.png,它應該看起來像這樣:

back refrences

最下面有紅字的盒子是我們感興趣的對象。我們可以看到,它被符號x引用了一次,被列表y引用了三次。如果是x引起了一個內存泄漏,我們可以使用這個方法,通過跟蹤它的所有引用,來檢查為什么它沒有自動的被釋放。

回顧一下,objgraph 使我們可以:

  • 顯示占據python程序內存的頭N個對象
  • 顯示一段時間以后哪些對象被刪除活增加了
  • 在我們的腳本中顯示某個給定對象的所有引用

努力與精度

在本帖中,我給你顯示了怎樣用幾個工具來分析python程序的性能。通過這些工具與技術的武裝,你可以獲得所有需要的信息,來跟蹤一個python程序中大多數的內存泄漏,以及識別出其速度瓶頸。

對許多其他觀點來說,運行一次性能分析就意味着在努力目標與事實精度之間做出平衡。如果感到困惑,那么就實現能適應你目前需求的最簡單的解決方案。

參考

 

補充部分工具使用方法

cProfile


 

cProfile是Python標准庫中包含的profile工具,使用方式如下,

import cProfile
import pstats

profile = cProfile.Profile()
profile.enable()
# your code hear
# ...
profile.disable()
pstats.Stats(profile).dump_stats('profile.prof')

需要profile的代碼放在enable/disable兩個函數調用之間,profile結果通過pstats導出到文件。實際開發中可以讓待profile的程序支持接收指令,動態開啟與關閉profile。

除了上面這個調用方法外,還可以使用run方法,或是在命令行下以-m方式加載cProfile,

def foobar():
  print 'foobar'

profile.run('foobar()')

 

python -m cProfile [-o output_file] [-s sort_order] myscript.py

pstats導出的結果可以用一些可視化工具查看。個人推薦通過PyCharm提供的Open cProfile Snapshots這個功能來進行查看。不僅能夠看到函數之間的調用關系,也可以直接進行代碼跳轉。

line_profiler


 

line_profiler可以進一步顯示Python函數每一行的用時開銷,

import line_profiler
import sys


def foo():
    for x in xrange(100):
        print x


profiler = line_profiler.LineProfiler(foo)
profiler.enable()
foo()
profiler.disable()
profiler.print_stats(sys.stdout)
Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     8                                           def foo():
     9       101           44      0.4     15.4      for x in xrange(100):
    10       100          242      2.4     84.6          print x

 

objgraph


 

objgraph是一個非常輕巧的工具,但在排查內存泄露的時候非常有用。objgraph的代碼很短,只有一個文件,其主要依靠標准庫中的gc模塊來獲取對象之間的創建引用關系。objgraph使用起來十分簡單,

# 列出最多實例的類型
objgraph.show_most_common_types(shortnames=False)
# 顯示兩次調用之間的對象數量變化
objgraph.show_growth(limit=None)
# 獲取指定類型的對象
objgraph.by_type('Foobar')
# 查找反向引用
objgraph.find_backref_chain(obj, objgraph.is_proper_module)
...

在遇到內存泄露問題時候首先考慮下用objgraph來進行查看,沒有問題的時候也可以學習下它的代碼,可以極大了解gc模塊的應用。

tracemalloc


 

tracemalloc是用來分析Python程序內存分配的工具,使用上也很簡單,

import tracemalloc
tracemalloc.start()

# ... run your application ...

snapshot = tracemalloc.take_snapshot()
top_stats = snapshot.statistics('lineno')

snapshot結果中可以看到每個模塊最終創建分配的內存大小,在追查內存問題上很有幫助。Python 3.5.x之后將tracemalloc集成到了標准庫當中,PEP-454

 

英文:Huy Nguyen

譯文:yexiaobai

鏈接:segmentfault.com/a/1190000000616798

補充工具原文地址 http://blog.soliloquize.org/2016/06/17/Python-Profile%E5%B7%A5%E5%85%B7%E6%8B%BE%E9%81%97/


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM