Categories
程式開發

在線代碼級性能剖析,補全分佈式追踪的最後一塊“短板”


在本文中,我們詳細介紹了代碼級的性能剖析方法,以及我們在Apache SkyWalking中的實踐。希望能夠幫助大家在線定位系統性能短板,緩解系統壓力。

分佈式鏈路追踪的局限性

在傳統的監控系統中,我們如果想要得知系統中的業務是否正常,會採用進程監控、日誌收集分析等方式來對系統進行監控。當機器或者服務出現問題時,則會觸發告警及時通知負責人。通過這種方式,我們可以得知具體哪些服務出現了問題。但是這時我們並不能得知具體的錯誤原因出在了哪裡,開發人員或者運維人員需要到日誌系統裡面查看錯誤日誌,甚至需要到真實的業務服務器上查看執行情況來解決問題。

如此一來,僅僅是發現問題的階段,可能就會耗費相當長的時間;另外,發現問題但是並不能追溯到問題產生具體原因的情況,也常有發生。這樣反反复復極其耗費時間和精力,為此我們便有了基於分佈式追踪的APM系統。

​通過將業務系統接入分佈式追踪中,我們就像是給程序增加了一個放大鏡功能,可以清晰看到真實業務請求的整體鏈路,包括請求時間、請求路徑,甚至是操作數據庫的語句都可以看得一清二楚。通過這種方式,我們結合告警便可以快速追踪到真實用戶請求的完整鏈路信息,並且這些數據信息完全是持久化的,可以隨時進行查詢,复盤錯誤的原因。

然而隨著我們對服務監控理解的加深,我們發現事情並沒有那麼簡單。在分佈式鏈路追踪中我們有這樣的兩個流派:代碼埋點和字節碼增強。無論使用哪種方式,底層邏輯一定都逃不過面向切面這個基礎邏輯。因為只有這樣才可以做到大面積的使用。這也就決定了它只能做到框架級別和RPC粒度的監控。這時我們可能依舊會遇到程序執行緩慢或者響應時間不穩定等情況,但無法具體查詢到原因。這時候,大家很自然的會考慮到增加埋點粒度,比如對所有的Spring Bean方法、甚至主要的業務層方法都加上埋點。但是這種思路會遇到不小的挑戰:

第一,增加埋點時系統開銷大,埋點覆蓋不夠全面。通過這種方式我們確實可以做到具體業務場景具體分析。但隨著業務不斷迭代上線,弊端也很明顯:大量的埋點無疑會加大系統資源的開銷,造成CPU、內存使用率增加,更有可能拖慢整個鏈路的執行效率。雖然每個埋點消耗的性能很小,在微秒級別,但是因為數量的增加,甚至因為業務代碼重用造成重複埋點或者循環使用,此時的性能開銷已經無法忽略。

第二,動態埋點作為一項埋點技術,和手動埋點的性能消耗上十分類似,只是減少的代碼修改量,但是因為通用技術的特別,上一個挑戰中提到的循環埋點和重複使用的場景甚至更為嚴重。比如選擇所有方法或者特定包下的所有方法埋點,很可能造成系統性能徹底崩潰。

第三,即使我們通過合理設計和埋點,解決了上述問題,但是JDK函數是廣泛使用的,我們很難限制對JDK API的使用場景。對JDK過多方法、特別是非RPC方法的監控會造成系統的巨大延遲風險。而且有一些基礎類型和底層工具類,是很難通過字節碼進行增強的。當我們的SDK使用不當或者出現bug時,我們無法具體得知真實的錯誤原因。

代碼級性能剖析方法

方法介紹

基於以上問題,在系統性能監控方法上,我們提出了代碼級性能剖析這種在線診斷方法。這種方法基於一個高級語言編程模型共性,即使再复雜的系統,再复雜的業務邏輯,都是基於線程去進行執行的,而且多數邏輯是在單個線程狀態下執行的。​

代碼級性能剖析就是利用方法棧快照,並對方法執行情況進行分析和匯總。並結合有限的分佈式追踪span上下文,對代碼執行速度進行估算。

性能剖析激活時,會對指定線程週期性的進行線程棧快照,並將所有的快照進行匯總分析,如果兩個連續的快照含有同樣的方法棧,則說明此棧中的方法大概率在這個時間間隔內都處於執行狀態。從而,通過這種連續快照的時間間隔累加成為估算的方法執行時間。時間估算方法如下圖所示:

在線代碼級性能剖析,補全分佈式追踪的最後一塊“短板” 1

在上圖中,d0-d10代表10次連續的內存棧快照,實際方法執行時間在d3-d4區間,結束時間在d8-d9之間。性能剖析無法告訴你方法的準確執行時間,但是他會估算出方法執行時間為d4-d8的4個快照採集間隔時間之和,這已經是非常的精確的時間估算了。

而這個過程因為不涉及代碼埋點,所以自然性能消耗是穩定和可控的,也無需擔心是否被埋點,是否是JDK方法等問題。同時,由於上層已經在分佈式追踪之下,性能剖析方法可以明確地確定分析開始和結束時間,減少不必要的性能開銷。

性能剖析可以很好的對線程的堆棧信息進行監控,主要有以下幾點優勢:

  1. 精確的問題定位,直接到代碼方法和代碼行;

  2. 無需反复的增刪埋點,大大減少了人力開發成本;

  3. 不用承擔過多埋點對目標系統和監控系統的壓力和性能風險;

  4. 按需使用,平時對系統無消耗,使用時的消耗穩定可能。

SkyWalking實踐實例

我們首先在Apache SkyWalking APM中實現此技術方法,下面我們就以一個真實的例子來說明此方法的執行效果。

final CountDownLatchcountDownLatch= new CountDownLatch(2);
threadPool.submit(new Task1(countDownLatch));
threadPool.submit(new Task2(countDownLatch));
try {
   countDownLatch.await(500, TimeUnit.MILLISECONDS);
} catch (InterruptedExceptione) {


}

這是我們故意加入的問題代碼,我們使用CountDownLanth設置了兩個任務完成後方法執行結束,Task1和Task2是兩個執行時間不穩定的任務,所以主任務也會執行速度不穩定。但對於運維和監控團隊來說,很難定位到這個方法片段。

針對於這種情況,我們看看性能剖析會怎樣直接定位此問題。

在線代碼級性能剖析,補全分佈式追踪的最後一塊“短板” 2

上圖所示的就是我們在進行鏈路追踪時所看到的真實執行情況,其中我們可以看到在service/processWithThreadPool執行速度緩慢,這正是我們植入問題代碼的方法。此時在這個調用中沒有後續鏈路了,所以並沒有更細緻的原因,我們也不打算去review代碼,從而增加新埋點。這時,我們可以對HelloService進行性能剖析,並執行只剖析響應速度大於500毫秒的請求。

注意,指定特定響應時間的剖析是保證剖析有效性的重要特性,如果方法在平均響應時間上已經出現問題,往往通過分佈式鏈路可以快速定位,因為此時鏈路總時間長,新埋點帶來的性能影響相對可控。但是方法性能抖動是不容易用新增埋點來解決的,而且往往只發生在生產環境。

在線代碼級性能剖析,補全分佈式追踪的最後一塊“短板” 3

上圖就是我們進行性能剖析後的真實結果圖。從左到右分別表示:棧幀名稱、該棧幀總計耗時(包含其下面所有自棧幀)、當前棧幀自身耗時和監控次數。我們可以在最後一行看到,線程卡在了sun.misc.Unsafe.park中了。如果你熟悉Java就可以知道此時進行了鎖等待,我們繼續按照樹的結構向上推,便可以看到線程真正是卡在了CountDownLatch.await方法中。

方法局限性

當然任何的方法都不是萬能的,性能剖析也有一些局限性。

第一, 對於高頻反复執行的方法,如循環調用,可能會誤報為緩慢方法。但這並不是大問題,因為如果反复執行的耗時較長,必然是系統需要關注的性能瓶頸。

第二, 由於性能棧快照有一定的性能消耗,所以採集週期不宜過密,如SkyWalking實踐中,不支持小於10ms的採集間隔。所以如果問題方法執行時間過小(比如在10毫秒內波動),此方法並不適用。我們也再此強調,方法論和工具的強大,始終不能代替程序員。

歡迎大家關注和支持該項目:
https://github.com/apache/skywalking

作者介紹:

吳晟,tetrate.io Fouding Engineer. Apache SkyWalking 創始人,PMC和VP。多個Apache項目成員。微軟MVP、阿里雲MVP、騰訊雲TVP。

劉晗,拉勾網技術專家,主要負責拉勾基礎組件和部分業務研發工作。 Apache SkyWalking Committer.