【編者按】原文作者 Emil Soman,Rubyist,除此之外竟然同時(shí)也是藝術(shù)家,吉他手,Garden City RubyConf 組織者。本文是DIY Ruby CPU Profiling 的第一部分,由 OneAPM 工程師編譯整理。

在 Codemancers,我們正在建設(shè) Rbkit——一個(gè)針對(duì) Ruby 語(yǔ)言的——擁有新炫酷功能的代碼分析器。我目前正在實(shí)現(xiàn)一個(gè)嵌在 rbkit gem 里的 CPU 分析器,這將有助 rbkit UI 重建分析 Ruby 進(jìn)程調(diào)用圖,并在屏幕上得出有用的可視化展示。在這個(gè)過(guò)程中,我學(xué)到了許多新東西,很樂(lè)意在本系列的博客文章中與您分享。
我們打算一步一步從基礎(chǔ)開始,專門為 Ruby 編寫一個(gè)初級(jí)的 CPU 分析器!在完成時(shí)我們將學(xué)到:
- 什么是 CPU 分析
- 分析模式——工具和采樣
- CPU Time 和 Wall Time ——它們分別是什么意思,如何測(cè)量?
- 寫一個(gè)簡(jiǎn)單的 C 擴(kuò)展并用于 Ruby 中
- Ruby Tracepoints——調(diào)用和返回
- C 語(yǔ)言中的信號(hào)處理
- 用一個(gè)信號(hào)暫停 Ruby 進(jìn)程并用調(diào)用堆查看
- 用分析數(shù)據(jù)進(jìn)行一些有用但笨拙的試驗(yàn)
Part I. 介紹 CPU 分析
通過(guò)對(duì)你的程序進(jìn)行 CPU 分析,可以發(fā)現(xiàn)相較于 CPU 使用率,你的程序是多么寶貴。為了分析程序,你需要使用一個(gè)分析工具并按照下列步驟操作:
- 開始 CPU 剖析
- 執(zhí)行你想要分析的代碼
- 停止 CPU 剖析并得到剖析結(jié)果
- 分析結(jié)果
- 通過(guò)分析剖析結(jié)果,你會(huì)發(fā)現(xiàn)使整個(gè)程序緩慢的瓶頸。
分析模式
CPU 剖析可以分為以下兩種方法:
1. 工具
在這種模式下,分析工具利用一些 hooks,由解釋器提供或者插入程序中,來(lái)了解調(diào)用圖并測(cè)量在調(diào)用圖中每個(gè)方法的執(zhí)行時(shí)間。舉個(gè)例子,看一下下面這段 Ruby 代碼:
def main
3.times do
find_many_square_roots
find_many_squares
end
end
def find_many_square_roots
5000.times{|i| Math.sqrt(i)}
end
def find_many_squares
5000.times{|i| i**2 }
end
main
我已經(jīng)插入了一些內(nèi)容,來(lái)幫助了解如果 Ruby 解釋器給了我們方法的調(diào)用和返回的 hooks,它們?nèi)绾螆?zhí)行:
def main
# method call hook gets executed
3.times do
find_many_square_roots
find_many_squares
end
# method end hook gets executed
end
def find_many_square_roots
# method call hook gets executed
5000.times{|i| Math.sqrt(i)}
# method end hook gets executed
end
def find_many_squares
# method call hook gets executed
5000.times{|i| i**2 }
# method end hook gets executed
end
main
現(xiàn)在,如果我們能夠打印出當(dāng)前時(shí)間和這些 hooks 內(nèi)部當(dāng)前方法的名稱,會(huì)得到看起來(lái)像這種形式的輸出結(jié)果:
sec:00 usec:201007 called main
sec:00 usec:201108 called find_many_square_roots
sec:00 usec:692123 returned find_many_square_roots
sec:00 usec:692178 called find_many_squares
sec:00 usec:846540 returned find_many_squares
sec:00 usec:846594 called find_many_square_roots
sec:01 usec:336166 returned find_many_square_roots
sec:01 usec:336215 called find_many_squares
sec:01 usec:484880 returned find_many_squares
sec:01 usec:484945 called find_many_square_roots
sec:01 usec:959254 returned find_many_square_roots
sec:01 usec:959315 called find_many_squares
sec:02 usec:106474 returned find_many_squares
sec:02 usec:106526 returned main
正如你所看到的,此輸出可以告訴我們?cè)诿恳环N方法里面花了多長(zhǎng)時(shí)間。同時(shí)也告訴我們,每一個(gè)方法調(diào)用的次數(shù)。這大概就解釋了性能分析工具是如何工作的。
優(yōu)點(diǎn):
高精度
我們得到了方法調(diào)用數(shù)
易于實(shí)施
缺點(diǎn):
每個(gè)被分析的方法執(zhí)行 hooks 時(shí)的額外開銷
2. 采樣
在采樣模式下,分析器每隔 x 時(shí)間單元打斷一次程序,并查看調(diào)用堆并記錄它的信息(被稱為“樣品”)。一旦該程序完成運(yùn)行,分析器收集所有樣品并找出每個(gè)方法出現(xiàn)在所有樣品中的次數(shù)。
很難想象?讓我們來(lái)看看同樣的例子代碼,看看如果我們使用采樣分析器,輸出結(jié)果會(huì)有怎樣的不同。
采樣分析器的輸出結(jié)果如下:
Call stack at 0.5sec: main/find_many_square_roots
Call stack at 1.0sec: main/find_many_square_roots
Call stack at 1.5sec: main/find_many_square_roots
Call stack at 2.0sec: main/find_many_squares
在這個(gè)例子中,程序每 0.5 秒被中斷一次并且調(diào)用堆棧被記錄。因此,通過(guò)這個(gè)程序執(zhí)行的過(guò)程我們得到了 4 個(gè)樣品,find_many_square_roots 記錄于 3 個(gè)樣品中, find_many_squares 只存在于一個(gè)樣品中。從本次采樣中,我們得到 find_many_square_roots 占用了 75% CPU,與此同時(shí) find_many_squares 只占用了 25% 的 CPU 。這就大概解釋了分析器是怎么樣工作的。
優(yōu)點(diǎn):
與工具分析相比開銷可忽略不計(jì)
很容易找到緩慢/長(zhǎng)時(shí)間運(yùn)行的方法
缺點(diǎn):
不擅長(zhǎng)測(cè)量短時(shí)間運(yùn)行的方法
我們沒(méi)有得到方法調(diào)用數(shù)
很難自己寫出采樣分析器
概括
我們只是調(diào)查了 CPU 分析的含義和兩種常用的 CPU 分析方法。在第 2 部分,我們將探討對(duì)描述 CPU 使用情況的 2 個(gè)單位進(jìn)行測(cè)量—— CPU Time 和 Wall Time。我們也會(huì)親手寫一些代碼來(lái)獲取進(jìn)行測(cè)量。感謝您的閱讀!
OneAPM for Ruby 能夠深入到所有 Ruby 應(yīng)用內(nèi)部完成應(yīng)用性能管理和監(jiān)控,包括代碼級(jí)別性能問(wèn)題的可見(jiàn)性、性能瓶頸的快速識(shí)別與追溯、真實(shí)用戶體驗(yàn)監(jiān)控、服務(wù)器監(jiān)控和端到端的應(yīng)用性能管理。 想閱讀更多技術(shù)文章,請(qǐng)?jiān)L問(wèn) OneAPM 官方博客。