Python 分析器

原始碼: Lib/profile.pyLib/pstats.py


分析器簡介

cProfileprofile 提供了 Python 程式的 確定性分析分析 (profile) 是一組統計資料,描述了程式的各個部分執行的頻率和時長。這些統計資料可以透過 pstats 模組格式化為報告。

Python 標準庫提供了兩種不同的對同一分析介面的實現:

  1. cProfile 推薦給大多數使用者使用;它是一個 C 擴充套件,具有合理的開銷,使其適用於分析長時間執行的程式。基於 lsprof,由 Brett Rosen 和 Ted Czotter 貢獻。

  2. profile,一個純 Python 模組,其介面被 cProfile 模仿,但它會給被分析的程式增加顯著的開銷。如果你想以某種方式擴充套件分析器,使用這個模組可能會更容易。最初由 Jim Roskind 設計和編寫。

備註

分析器模組旨在為給定程式提供執行分析,而不是用於基準測試(為此,有 timeit 模組可以提供相當準確的結果)。這尤其適用於將 Python 程式碼與 C 程式碼進行基準測試:分析器會給 Python 程式碼引入開銷,但不會給 C 級別的函式引入開銷,因此 C 程式碼看起來會比任何 Python 程式碼都快。

即時使用者手冊

本節為“不想閱讀手冊”的使用者提供。它提供了一個非常簡短的概述,並允許使用者快速對現有應用程式執行分析。

要分析一個接受單個引數的函式,你可以這樣做:

import cProfile
import re
cProfile.run('re.compile("foo|bar")')

(如果你的系統上沒有 cProfile,請使用 profile 代替。)

上述操作將執行 re.compile() 並打印出類似以下的分析結果:

      214 function calls (207 primitive calls) in 0.002 seconds

Ordered by: cumulative time

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1    0.000    0.000    0.002    0.002 {built-in method builtins.exec}
     1    0.000    0.000    0.001    0.001 <string>:1(<module>)
     1    0.000    0.000    0.001    0.001 __init__.py:250(compile)
     1    0.000    0.000    0.001    0.001 __init__.py:289(_compile)
     1    0.000    0.000    0.000    0.000 _compiler.py:759(compile)
     1    0.000    0.000    0.000    0.000 _parser.py:937(parse)
     1    0.000    0.000    0.000    0.000 _compiler.py:598(_code)
     1    0.000    0.000    0.000    0.000 _parser.py:435(_parse_sub)

第一行表示監控了 214 次呼叫。在這些呼叫中,有 207 次是 原始的 (primitive),意味著這次呼叫不是透過遞迴引起的。下一行:Ordered by: cumulative time 表示輸出是按 cumtime 值排序的。列標題包括:

ncalls

呼叫的次數。

tottime

在給定函式中花費的總時間(不包括呼叫子函式的時間)

percall

tottime 除以 ncalls 的商

cumtime

是在此函式和所有子函式中花費的累積時間(從呼叫到退出)。這個數字即使對於遞迴函式也是準確的。

percall

cumtime 除以原始呼叫次數的商

filename:lineno(function)

提供每個函式的相應資料

當第一列有兩個數字時(例如 3/1),表示該函式發生了遞迴。第二個值是原始呼叫的次數,前一個值是總呼叫次數。請注意,當函式不遞迴時,這兩個值是相同的,並且只打印單個數字。

你也可以不把輸出列印在分析執行的末尾,而是透過為 run() 函式指定一個檔名來將結果儲存到檔案中:

import cProfile
import re
cProfile.run('re.compile("foo|bar")', 'restats')

pstats.Stats 類從檔案中讀取分析結果,並以各種方式格式化它們。

cProfileprofile 檔案也可以作為指令碼呼叫來分析另一個指令碼。例如:

python -m cProfile [-o output_file] [-s sort_order] (-m module | myscript.py)
-o <output_file>

將分析結果寫入檔案,而不是標準輸出。

-s <sort_order>

指定 sort_stats() 的排序值之一來對輸出進行排序。這僅在未提供 -o 時適用。

-m <module>

指定正在分析的是一個模組而不是一個指令碼。

在 3.7 版本加入: cProfile 添加了 -m 選項。

在 3.8 版本加入: profile 添加了 -m 選項。

pstats 模組的 Stats 類有多種方法用於操作和列印儲存到分析結果檔案中的資料:

import pstats
from pstats import SortKey
p = pstats.Stats('restats')
p.strip_dirs().sort_stats(-1).print_stats()

strip_dirs() 方法從所有模組名稱中移除了多餘的路徑。sort_stats() 方法根據列印的標準模組/行/名稱字串對所有條目進行排序。print_stats() 方法打印出所有統計資訊。你可以嘗試以下排序呼叫:

p.sort_stats(SortKey.NAME)
p.print_stats()

第一個呼叫實際上會按函式名對列表進行排序,第二個呼叫會打印出統計資訊。以下是一些有趣的呼叫可以嘗試:

p.sort_stats(SortKey.CUMULATIVE).print_stats(10)

這將按函式中的累積時間對分析結果進行排序,然後只打印最重要的十行。如果你想了解哪些演算法耗時,上面這行就是你所需要的。

如果你想檢視哪些函式迴圈次數多且耗時,你可以這樣做:

p.sort_stats(SortKey.TIME).print_stats(10)

以根據每個函式內部花費的時間進行排序,然後列印前十個函式的統計資訊。

你也可以嘗試:

p.sort_stats(SortKey.FILENAME).print_stats('__init__')

這將按檔名對所有統計資料進行排序,然後只打印類初始化方法的統計資訊(因為它們的名字中帶有 __init__)。作為最後一個例子,你可以嘗試:

p.sort_stats(SortKey.TIME, SortKey.CUMULATIVE).print_stats(.5, 'init')

此行以時間為主鍵,累積時間為次鍵對統計資訊進行排序,然後打印出部分統計資訊。具體來說,列表首先被縮減到其原始大小的 50%(re: .5),然後只保留包含 init 的行,並列印該子列表。

如果你想知道哪些函式呼叫了上述函式,你現在可以(p 仍然按照最後一個標準排序)這樣做:

p.print_callers(.5, 'init')

你會得到一個列出的每個函式的呼叫者列表。

如果你想要更多功能,你需要閱讀手冊,或者猜測以下函式的作用:

p.print_callees()
p.add('restats')

當作為指令碼呼叫時,pstats 模組是一個用於讀取和檢查分析轉儲檔案的統計瀏覽器。它有一個簡單的面向行的介面(使用 cmd 實現)和互動式幫助。

profilecProfile 模組參考

profilecProfile 模組都提供了以下函式:

profile.run(command, filename=None, sort=-1)

該函式接受一個可以傳遞給 exec() 函式的單個引數,以及一個可選的檔名。在所有情況下,此例程都會執行:

exec(command, __main__.__dict__, __main__.__dict__)

並從執行中收集分析統計資料。如果沒有檔名,則此函式會自動建立一個 Stats 例項並列印一個簡單的分析報告。如果指定了排序值,它將被傳遞給此 Stats 例項以控制結果的排序方式。

profile.runctx(command, globals, locals, filename=None, sort=-1)

此函式與 run() 類似,但增加了引數來為 command 字串提供全域性和區域性名稱空間對映。此例程執行:

exec(command, globals, locals)

並像上面的 run() 函式一樣收集分析統計資料。

class profile.Profile(timer=None, timeunit=0.0, subcalls=True, builtins=True)

這個類通常只在需要比 cProfile.run() 函式提供的更精確的分析控制時使用。

可以透過 timer 引數提供一個自定義的計時器來測量程式碼執行所需的時間。這必須是一個返回表示當前時間的單個數字的函式。如果該數字是整數,則 timeunit 指定一個乘數,用於指定每個時間單位的持續時間。例如,如果計時器返回以千分之一秒為單位測量的時間,則時間單位將為 .001

直接使用 Profile 類可以格式化分析結果,而無需將分析資料寫入檔案:

import cProfile, pstats, io
from pstats import SortKey
pr = cProfile.Profile()
pr.enable()
# ... do something ...
pr.disable()
s = io.StringIO()
sortby = SortKey.CUMULATIVE
ps = pstats.Stats(pr, stream=s).sort_stats(sortby)
ps.print_stats()
print(s.getvalue())

Profile 類也可以用作上下文管理器(僅在 cProfile 模組中支援。參見 上下文管理器型別):

import cProfile

with cProfile.Profile() as pr:
    # ... do something ...

    pr.print_stats()

在 3.8 版本發生變更: 添加了上下文管理器支援。

enable()

開始收集分析資料。僅在 cProfile 中可用。

disable()

停止收集分析資料。僅在 cProfile 中可用。

create_stats()

停止收集分析資料,並將結果作為當前分析在內部記錄。

print_stats(sort=-1)

基於當前分析建立一個 Stats 物件,並將結果列印到標準輸出。

sort 引數指定了顯示統計資訊的排序順序。它接受一個鍵或一個鍵的元組以啟用多級排序,就像在 Stats.sort_stats 中一樣。

在 3.13 版本加入: print_stats() 現在接受一個鍵的元組。

dump_stats(filename)

將當前分析的結果寫入 filename

run(cmd)

透過 exec() 分析 cmd。

runctx(cmd, globals, locals)

透過 exec() 使用指定的全域性和區域性環境分析 cmd。

runcall(func, /, *args, **kwargs)

分析 func(*args, **kwargs)

請注意,只有當被呼叫的命令/函式實際返回時,分析才會起作用。如果直譯器被終止(例如,在被呼叫的命令/函式執行期間透過 sys.exit() 呼叫),則不會列印任何分析結果。

Stats

分析器資料的分析是使用 Stats 類完成的。

class pstats.Stats(*filenames or profile, stream=sys.stdout)

這個類的建構函式從一個 filename(或檔名列表)或一個 Profile 例項建立一個“統計物件”的例項。輸出將被列印到由 stream 指定的流中。

上述建構函式選擇的檔案必須是由相應版本的 profilecProfile 建立的。具體來說,與此分析器的未來版本保證檔案相容性,並且與其他分析器生成的檔案或在不同作業系統上執行的相同分析器生成的檔案不相容。如果提供了多個檔案,所有相同函式的統計資料將被合併,以便可以在一個報告中考慮多個程序的總體檢視。如果需要將其他檔案與現有 Stats 物件中的資料結合起來,可以使用 add() 方法。

除了從檔案中讀取分析資料,還可以使用 cProfile.Profileprofile.Profile 物件作為分析資料來源。

Stats 物件有以下方法:

strip_dirs()

這個 Stats 類的方法會從檔名中移除所有前導路徑資訊。這在減少列印輸出的大小以適應(接近)80列時非常有用。此方法會修改物件,被剝離的資訊會丟失。執行剝離操作後,該物件的條目被認為處於“隨機”順序,就像物件初始化和載入後一樣。如果 strip_dirs() 導致兩個函式名無法區分(它們在同一檔案的同一行,並且具有相同的函式名),那麼這兩個條目的統計資料將累積到一個條目中。

add(*filenames)

Stats 類的這個方法將額外的分析資訊累積到當前的分析物件中。它的引數應該引用由相應版本的 profile.run()cProfile.run() 建立的檔名。對於同名(即檔案、行號、名稱相同)的函式的統計資料會自動累積到單個函式統計中。

dump_stats(filename)

將載入到 Stats 物件中的資料儲存到名為 filename 的檔案中。如果檔案不存在,則建立該檔案;如果檔案已存在,則覆蓋它。這與 profile.ProfilecProfile.Profile 類上的同名方法等效。

sort_stats(*keys)

此方法透過根據提供的標準對 Stats 物件進行排序來修改它。引數可以是字串或 SortKey 列舉,用於標識排序的依據(例如:'time', 'name', SortKey.TIMESortKey.NAME)。SortKey 列舉引數比字串引數的優勢在於它更健壯且不易出錯。

當提供多個鍵時,如果之前選擇的所有鍵都相等,則使用附加鍵作為次要標準。例如,sort_stats(SortKey.NAME, SortKey.FILE) 將根據函式名對所有條目進行排序,並透過按檔名排序來解決所有平局(函式名相同的情況)。

對於字串引數,任何鍵名都可以使用縮寫,只要縮寫是明確的。

以下是有效的字串和 SortKey:

有效字串引數

有效列舉引數

含義

'calls'

SortKey.CALLS

呼叫次數

'cumulative'

SortKey.CUMULATIVE

累積時間

'cumtime'

N/A

累積時間

'file'

N/A

檔名

'filename'

SortKey.FILENAME

檔名

'module'

N/A

檔名

'ncalls'

N/A

呼叫次數

'pcalls'

SortKey.PCALLS

原始呼叫次數

'line'

SortKey.LINE

行號

'name'

SortKey.NAME

函式名

'nfl'

SortKey.NFL

名稱/檔案/行

'stdname'

SortKey.STDNAME

標準名稱

'time'

SortKey.TIME

內部時間

'tottime'

N/A

內部時間

請注意,所有統計資料的排序都是降序的(將耗時最多的項放在前面),而名稱、檔案和行號的搜尋是升序的(按字母順序)。SortKey.NFLSortKey.STDNAME 之間的細微區別在於,標準名稱是按列印的名稱排序,這意味著嵌入的行號會以一種奇怪的方式進行比較。例如,行 3、20 和 40(如果檔名相同)將以字串順序 20、3 和 40 出現。相比之下,SortKey.NFL 會對行號進行數字比較。實際上,sort_stats(SortKey.NFL)sort_stats(SortKey.NAME, SortKey.FILENAME, SortKey.LINE) 相同。

出於向後相容性的原因,允許使用數字引數 -1012。它們分別被解釋為 'stdname''calls''time''cumulative'。如果使用這種舊式格式(數字),則只會使用一個排序鍵(數字鍵),並且會靜默忽略其他引數。

在 3.7 版本加入: 添加了 SortKey 列舉。

reverse_order()

這個 Stats 類的方法會反轉物件內基本列表的順序。請注意,預設情況下,升序與降序會根據所選的排序鍵正確選擇。

print_stats(*restrictions)

Stats 類的這個方法會打印出 profile.run() 定義中描述的報告。

列印的順序是基於物件上最後一次 sort_stats() 操作(受 add()strip_dirs() 中的注意事項限制)。

提供的引數(如果有)可用於將列表限制為重要的條目。最初,列表被視為已分析函式的完整集合。每個限制可以是整數(選擇行數)、0.0 到 1.0 之間的小數(選擇行百分比)或將被解釋為正則表示式的字串(用於模式匹配列印的標準名稱)。如果提供了多個限制,則它們將按順序應用。例如:

print_stats(.1, 'foo:')

將首先將列印限制為列表的前 10%,然後只打印屬於檔名 .*foo: 的函式。相比之下,命令

print_stats('foo:', .1)

會將列表限制為所有檔名為 .*foo: 的函式,然後只打印其中的前 10%。

print_callers(*restrictions)

Stats 類的這個方法打印出分析資料庫中每個函式的呼叫者列表。排序與 print_stats() 提供的相同,限制引數的定義也相同。每個呼叫者都在自己的行上報告。格式根據生成統計資料的分析器略有不同:

  • 使用 profile 時,每個呼叫者後面都會顯示一個括號中的數字,以顯示該特定呼叫被執行了多少次。為了方便,右側會重複顯示一個非括號中的數字,表示在該函式中花費的累積時間。

  • 使用 cProfile 時,每個呼叫者前面都有三個數字:此特定呼叫被執行的次數,以及當此特定呼叫者呼叫時,在當前函式中花費的總時間和累積時間。

print_callees(*restrictions)

Stats 類的這個方法會打印出被指定函式呼叫的所有函式的列表。除了呼叫方向相反(即:被呼叫 vs. 呼叫者),引數和排序與 print_callers() 方法相同。

get_stats_profile()

此方法返回一個 StatsProfile 的例項,其中包含函式名到 FunctionProfile 例項的對映。每個 FunctionProfile 例項都包含與函式分析相關的資訊,例如函式運行了多長時間、被呼叫了多少次等。

在 3.9 版本加入: 添加了以下資料類:StatsProfile、FunctionProfile。添加了以下函式:get_stats_profile。

什麼是確定性分析?

確定性分析 (Deterministic profiling) 旨在反映所有*函式呼叫*、*函式返回*和*異常*事件都被監控,並且對這些事件之間的間隔(使用者程式碼執行期間)進行精確計時。相比之下,統計分析 (statistical profiling)(本模組未實現)會隨機抽樣有效的指令指標,並推斷時間花費在哪裡。後一種技術傳統上開銷較小(因為程式碼不需要被插樁),但只提供了時間花費的相對指示。

在 Python 中,由於在執行期間有一個活動的直譯器,因此不需要插樁程式碼來進行確定性分析。Python 會自動為每個事件提供一個 鉤子(可選的回撥)。此外,Python 的解釋性特性往往會給執行增加很多開銷,以至於確定性分析在典型應用中通常只增加很小的處理開銷。結果是確定性分析並不昂貴,卻能提供關於 Python 程式執行的廣泛執行時統計資訊。

呼叫計數統計可用於識別程式碼中的錯誤(意外的計數),並識別可能的內聯擴充套件點(高呼叫計數)。內部時間統計可用於識別應仔細最佳化的“熱迴圈”。累積時間統計應用於識別演算法選擇中的高階錯誤。請注意,此分析器對累積時間的特殊處理允許將演算法的遞迴實現的統計資料直接與迭代實現進行比較。

限制

一個限制與計時資訊的準確性有關。確定性分析器在準確性方面存在一個根本性問題。最明顯的限制是底層的“時鐘”僅以(通常)約 0.001 秒的速率計時。因此,任何測量都不會比底層時鐘更準確。如果進行足夠多的測量,那麼“誤差”將趨於平均。不幸的是,消除這第一個誤差會引入第二個誤差源。

第二個問題是,從事件被分派到分析器呼叫獲取時間*實際*獲取時鐘狀態需要“一段時間”。類似地,從獲取時鐘值(然後儲存起來)到使用者程式碼再次執行,退出分析器事件處理程式時也存在一定的延遲。因此,被多次呼叫的函式或呼叫許多函式的函式通常會累積這種誤差。以這種方式累積的誤差通常小於時鐘的精度(小於一個時鐘滴答),但它*可以*累積並變得非常顯著。

這個問題對於 profile 模組比對於開銷更低的 cProfile 更為重要。因此,profile 提供了一種針對給定平臺進行校準的方法,以便可以機率性地(平均而言)消除此誤差。分析器校準後,它將更準確(在最小二乘意義上),但有時會產生負數(當呼叫次數異常低,且機率之神與你作對時 :-) )。不要對分析中的負數感到驚慌。它們*只有*在您校準了分析器後才應該出現,並且結果實際上比未校準時更好。

校準

profile 模組的分析器會從每個事件處理時間中減去一個常數,以補償呼叫時間函式和儲存結果的開銷。預設情況下,該常數為 0。可以使用以下過程為給定平臺獲取一個更好的常數(參見 限制)。

import profile
pr = profile.Profile()
for i in range(5):
    print(pr.calibrate(10000))

該方法直接執行引數給定的 Python 呼叫次數,並在分析器下再次執行,測量兩者的時間。然後它計算每個分析器事件的隱藏開銷,並將其作為浮點數返回。例如,在執行 macOS 的 1.8GHz Intel Core i5 上,使用 Python 的 time.process_time() 作為計時器,這個神奇的數字大約是 4.04e-6。

這個練習的目的是得到一個相當一致的結果。如果你的計算機*非常*快,或者你的計時器函式解析度很差,你可能需要傳遞 100000,甚至 1000000,才能得到一致的結果。

當您得到一個一致的答案時,有三種方式可以使用它:

import profile

# 1. Apply computed bias to all Profile instances created hereafter.
profile.Profile.bias = your_computed_bias

# 2. Apply computed bias to a specific Profile instance.
pr = profile.Profile()
pr.bias = your_computed_bias

# 3. Specify computed bias in instance constructor.
pr = profile.Profile(bias=your_computed_bias)

如果你有選擇,最好選擇一個較小的常數,這樣你的結果在分析統計中顯示為負數的可能性就會“更小”。

使用自定義計時器

如果你想改變確定當前時間的方式(例如,強制使用掛鐘時間或經過的程序時間),請將你想要的計時函式傳遞給 Profile 類的建構函式:

pr = profile.Profile(your_time_func)

生成的分析器隨後將呼叫 your_time_func。根據您使用的是 profile.Profile 還是 cProfile.Profileyour_time_func 的返回值將被不同地解釋:

profile.Profile

your_time_func 應該返回一個單獨的數字,或者一個其總和為當前時間的數字列表(就像 os.times() 返回的那樣)。如果函式返回一個單獨的時間數字,或者返回的數字列表長度為 2,那麼你將得到一個特別快的排程例程版本。

請注意,你應該為你選擇的計時器函式校準分析器類(參見 校準)。對於大多數機器,返回單個整數值的計時器在分析期間的低開銷方面會提供最好的結果。(os.times() 相當糟糕,因為它返回一個浮點值的元組)。如果你想以最乾淨的方式替換一個更好的計時器,請派生一個類並硬編碼一個最能處理你的計時器呼叫的替換排程方法,以及適當的校準常數。

cProfile.Profile

your_time_func 應該返回一個單獨的數字。如果它返回整數,你還可以在呼叫類建構函式時使用第二個引數指定一個時間單位的實際持續時間。例如,如果 your_integer_time_func 返回以千分之一秒為單位測量的時間,你應該如下構造 Profile 例項:

pr = cProfile.Profile(your_integer_time_func, 0.001)

由於 cProfile.Profile 類無法校準,因此應謹慎使用自定義計時器函式,並應儘可能快。為了在使用自定義計時器時獲得最佳結果,可能需要在內部 _lsprof 模組的 C 原始碼中對其進行硬編碼。

Python 3.3 在 time 模組中添加了幾個新函式,可用於精確測量程序時間或掛鐘時間。例如,參見 time.perf_counter()