你好! 我作為一名編寫Ruby profiler的先驅,我想對現有的Ruby和Python profiler如何工作進行一次調查。 這也有助於回答很多人的問題:“你怎麼寫一個profiler?”
在這篇文章中,我們只關注CPUprofiler(而不是記憶體/堆profiler)。 我將解釋一些編寫profiler的一般基本方法,給出一些程式碼示例,以及大量流行的Ruby和Pythonprofiler的例子,並告訴你它們是如何工作的。
在這篇文章中可能會有一些錯誤(為了研究這篇文章,我閱讀了14個不同的分析庫的程式碼部分),請讓我們開始吧!
2種不同的profilers
有兩種基本CPU profilers型別 – sampling profilers和tracing profilers。
tracingprofilers記錄您的程式所呼叫的每個函式,然後在最後列印出報告。 samplingprofilers採用更加統計化的方法 – 他們每隔幾毫秒記錄程式的堆疊情況,然後報告結果。
使用sampling profilers而不是tracing profilers的主要原因是sampling profilers的開銷較低。 如果每秒只抽取20或200個樣本,那不會花費多少時間。 而且它們非常有效率 – 如果您遇到嚴重的效能問題(比如80%的時間花費在1個慢速函式上),那麼每秒200個樣本通常就足以確定那個函式的問題所在了!
分析器
下邊類出了我們這篇文章要討論的分析器(來源)。我之後將會解釋表格中的術語(setitimer, rb_add_event_hook, ptrace)。這裡最有趣的是,所有的分析器都是通過一小部分函式的特性實現的。
python分析器
Name | Kind | How it works |
---|---|---|
cProfile | Tracing | PyEval_SetProfile |
line_profiler | Tracing | PyEval_SetTrace |
pyflame (blog post) | Sampling | ptrace + custom timing |
stacksampler | Sampling | setitimer |
statprof | Sampling | setitimer |
vmprof | Sampling | setitimer |
pyinstrument | Sampling | PyEval_SetProfile |
gprof (greenlet) | Tracing | greenlet.settrace |
python-flamegraph | Sampling | profiling thread + custom timing |
gdb hacks | Sampling | ptrace |
“gbd hacks”並不完全是一個Python分析器:它是一個講述如何實現用指令碼包裝gdb來實現hacky分析器的連結。由於新版本的gdb事實上會展開Python堆疊,所以也是和Python有關的。一種簡化版的pyflame。
Ruby分析器
Name | Kind | How it works |
---|---|---|
stackprof by tmm1 | Sampling | setitimer |
perftools.rb by tmm1 | Sampling | setitimer |
rblineprof by tmm1 | Tracing | rb_add_event_hook |
ruby-prof | Tracing | rb_add_event_hook |
flamegraph | Sampling | stackprof gem |
這些分析器中幾乎所有的都存在你的程式裡面。
在我們開始詳細分析這些分析器之前,有一個非常重要的事情需要說明一下:除fyflame外所有的分析器都執行在你的Python/Ruby程式裡面。如果你在一個Python/Ruby程式裡面,你通常可以很容易的獲取該程式的堆疊。例如下邊程式碼中的簡單的Python程式答應出每一個執行執行緒的堆疊:
1 2 3 4 5 6 7 8 9 10 11 12 |
import sys import traceback def bar(): foo() def foo(): for _, frame in sys._current_frames().items(): for line in traceback.extract_stack(frame): print line bar() |
你可以從下邊的輸出裡面看到堆疊的函式名,行號,檔名等你在做分析的時候需要的所有資訊。
1 2 3 |
('test2.py', 12, '<module>', 'bar()') ('test2.py', 5, 'bar', 'foo()') ('test2.py', 9, 'foo', 'for line in traceback.extract_stack(frame):') |
在Ruby程式中,獲取堆疊也很容易:你只需要通過caoller來獲取堆疊。
這些分析器處於效能考慮都是C擴充套件所有它們有一點不一樣,但是Ruby/Python程式的C擴充套件也可以很容易的獲取呼叫堆疊。
追蹤分析器是如何工作的
我調查過上邊表格中所有的追蹤分析器:rblineprof、ruby-prof和cProfile。它們工作原理基本相同。它們都記錄所有的函式呼叫並且用C語言編寫來降低耗時。
它們是如何工作的呢?Ruby和Python都允許指定一個回撥函式,當各種解釋事件(例如呼叫一個函式或者執行一行程式碼)發生的時候呼叫。當回撥函式被呼叫的時候,會記錄堆疊供以後分析。
我認為確切瞭解在程式碼中哪裡設定這些回撥函式是很有用的,所以我連線了所有在github上邊的相關程式碼。
在Python中,可以通過PyEval_SetTrace或者 PyEval_SetProfile設定回撥函式。在Python官方文件的分析和追蹤裡有說明。文件中說道:除了追蹤函式會收到line-number事件外“PyEval_SetTrace和PyEval_SetProfile一樣。
程式碼:
- line_profiler 使用PyEval_SetTrace設定回撥:看line_profiler.pyx的157行
- cProfiles 使用PyEval_SetProfile設定回撥:看_lsprof.c的693行(cProfile是用Isprof實現的)
在Ruby裡,你可以用rb_add_event_hook來設定回撥,我找不到任何關於此處是如何呼叫的文件
1 2 3 4 |
rb_add_event_hook(prof_event_hook, RUBY_EVENT_CALL | RUBY_EVENT_RETURN | RUBY_EVENT_C_CALL | RUBY_EVENT_C_RETURN | RUBY_EVENT_LINE, self); |
prof_event_hook的型別是
1 2 |
static void prof_event_hook(rb_event_flag_t event, VALUE data, VALUE self, ID mid, VALUE klass) |
這看起來像極了Python的PyEval_SetTrace,但是比Python更靈活——您可以選擇你關注的事件型別(就像“函式呼叫”一樣)。
程式碼:
- ruby-prof 呼叫rb_add_event在:ruby-prof.c line 329
- rblineprof呼叫rb_add_event_hook在:rblineprof.c line 649
追蹤分析器的缺點
追蹤分析器的主要的缺點是它的實現方式是對於每個函式/行程式碼都執行固定的次數,這樣可能使你做出錯誤的決定。例如,如果你有某個事物的兩個實現:一個通過大量的函式呼叫實現,另一個沒有大量函式呼叫,兩個實現耗時相同,有大量函式呼叫的相比沒有大量函式呼叫的在分析的時候會變得慢。
為了測試這一點,我做了一個包含下邊內容的小檔案test.py,並且比較了python -mcProfile test.py和python test.py的耗時。python test.py執行需要大約0.6秒,python -mcProfile test.py執行需要大約1秒。對於這個特定的例子cProfile引入了額外的大約60%的開銷。
1 2 3 4 5 6 7 |
def recur(n): if n == 0: return recur(n-1) for i in range(5000): recur(700) |
cProfile文件中說:
Python的解釋語言的特性往往會增加執行的開銷,對於典型的應用確定性分析僅僅會增加很少執行開銷。
這似乎是一個合理的說法:上邊的示例(執行350萬次函式呼叫)顯然不是個典型的Python程式,並且幾乎任何其他程式開銷都比該示例小。
我沒有測試ruby-prof(一個ruby追蹤分析器)的開銷,但是它的README說:
大多數程式開分析器耗時將會是原來的兩倍,並且高度遞迴程式(斐波那契數列)耗時將會是原來的三倍。
取樣分析器都怎麼工作的:setitimer
現在討論第二種分析器:取樣分析器。
大多數Ruby和Python的取樣分析器都是通過系統呼叫setitimer實現的。這是怎麼回事呢?
好吧,比方說你想要每秒獲取一個程式的堆疊50次,一種方法是:
- 請求Linux核心每20毫秒給你傳送一個訊號(使用系統呼叫setitimer)
- 註冊一個訊號處理器在每次獲得訊號的時候記錄堆疊。
- 當結束分析的時候,請求Linux停止傳送訊號並且列印輸出。
如果你想要看一個實際的用setitimer實現取樣分析器的例子的話,我認為stacksampler.py是一個最好的例子,stacksampler.py是一個有用的有效的分析器並且程式碼只有大約100行,好酷啊!
stacksampler.py只有100多行的一個原因是:當你把一個Python函式註冊成訊號處理器的時候,該函式被傳送到你的Python程式的當前堆疊中。所以stacksampler.py訊號處理器註冊是非常簡單的:
1 2 3 4 5 6 7 8 |
def _sample(self, signum, frame): stack = [] while frame is not None: stack.append(self._format_frame(frame)) frame = frame.f_back stack = ';'.join(reversed(stack)) self._stack_counts[stack] += 1 |
它只是將堆疊從堆疊幀中取出來並且增加堆疊檢視計數,非常簡單!非常酷!
我們看繼續剩下的使用setitimer的分析器並找到它們呼叫settimer的程式碼:
- stackprof (Ruby): in stackprof.c line 118
- perftools.rb (Ruby): in this patch which seems to be applied when the gem is compiled (?)
- stacksampler (Python): stacksampler.py line 51
- statprof (Python): statprof.py line 239
- vmprof (Python): vmprof_unix.c line 294
關於setitimer很重要的一點是,你需要決定如何計算時間。你想要真正的20 ms的“掛鐘”時間?你想要20 ms的使用者CPU時間?或者20 ms的使用者+系統CPU時間?如果你仔細看電話網站上的內容,你就會發現,這些分析器實際上對setitimer做出了不同的選擇 — 有時候它是可配置的,有時候卻不可。setitimer手冊頁十分精悍,並且值得去讀懂上面所有的觀點。
@mgedmin 在推特上指出了一個使用setitimer時出現的有趣的問題,這個問題和這個問題擁有的一系列更多細節。
一個有趣的基於setitimer分析器的問題就是定時器產生的訊號!訊號有時候能中斷系統呼叫!系統呼叫有時候需要幾毫秒!如果測試太平凡,你會讓你的程式永遠迴圈執行系統呼叫!
不使用setitimer的取樣分析器
有些取樣分析器不使用setitimer:
- pyinstrument使用PyEval_SetProfile(所以它在某種程度上是跟蹤分析器),但是當它的跟蹤回撥函式被呼叫時,它並不總是收集堆疊樣本。下面是選擇何時測試堆疊跟蹤的程式碼。更多資訊,請看這篇部落格文章。 (真相: setitimer帶你瞭解Python中的主執行緒)
- pyflame簡要介紹了Python程式碼在外部呼叫ptracesystem的過程。根本上來講,它只是一個抓取樣本,睡眠,重複的迴圈,這裡是sleep呼叫。
- python-flamegraph以類似的方式在你的Python操作中開啟一個新的執行緒並且抓取堆疊跟蹤,睡眠,和重複。這裡是sleep呼叫。
所有這3個分析器使用掛鐘定時取樣。
pyflame 部落格
有很多關於pyflame是如何工作的。我不打算在這裡進行介紹,但是Evan Klitke寫了很多關於它的非常好的部落格:
- Pyflame:超級工程的Ptracing的Python分析器來介紹pyflame
- Pyflame雙解析器模式關於如何同時支援Python2和Python3
- 意想不到的python ABI變動增加了Python3.6的支援
- 釋放多執行緒Python堆疊
- Pyflame打包
- 在Python中一個關於ptrace+syscalls的有趣的問題
- 使用ptrace的樂趣和好處,ptrace(續)
還有很多在 https://eklitzke.org/。所有有趣的東西,我會更詳細地閱讀——也許ptrace是比實現一個Ruby分析器process_vm_readv更好的方法!(process_vm_readv開銷低,因為它不會阻斷程式,但它也可以給你一個不一致的快照,因為它不會阻斷程式:))
先講解到這裡了!
在這篇文章中我沒有涉及很多重要的細節 – 比如我基本上說vmprof和stacksampler是一樣的(但實際上它們不是 – vmprof支援線性分析和用C語言編寫的Python函式分析,我相信這在分析器中引入了更多的複雜性)。 但一些基本原理是一樣的,所以我認為這項調查是一個很好的起點。