博客 / 詳情

返回

慢調用鏈診斷利器 - ARMS 代碼熱點

可觀測技術背景

從最早的 Google 發表的一篇名為《Dapper, a Large-Scale Distributed Systems Tracing Infrastructure》的論文開始,到後來以:Metrics(指標)、Tracing(鏈路追蹤)以及 Logging(日誌)三大方向互為補充的可觀測解決方案逐漸被業界所接受併成為事實標準。

圖片

基於上述全棧可觀測方案技術,診斷一個問題從之前的無從下手或者僅單靠日誌變成為如下步驟:

  1. 通過 Metrics/Logs 提供的各式各樣預設報警發現應用異常信息確定異常模塊
  2. 對異常模塊以及關聯日誌(Logs)進行查詢分析,找到核心的報錯信息
  3. 通過詳細的調用鏈數據(Tracing)定位到引起問題的代碼片段。

基於上述一整套可觀測解決方案,不僅可在問題發生後快速定位問題,及時減損,很多時候甚至可以在大故障發生前,就實現對問題的提前發現和解決修復。

監控盲區

是否基於上述一整套可觀測解決方案就可以一勞永逸,解決線上任何的監控問題了呢?其實不然,特別是在 Tracing 方面,由於一般其都是基於 Java Agent/SDK 技術方案對主流如 HTTP 服務、RPC 服務、數據庫、分佈式消息 MQ 等軟件開發框架進行埋點採集調用鏈監控數據,然後再通過後續的調用鏈數據還原處理邏輯將監控信息與具體的請求關聯在一起,從而實現當請求發生異常時,通過採集的監控數據就能查看到相關調用信息。調用鏈除了可以提供一次請求經過的核心鏈路方法外,另外一個核心作用就是幫助排查一個調用鏈中的耗時慢位置幫助做代碼優化。具體排查過程可通過類似如下圖所示的調用鏈詳細信息對調用鏈中的耗時瓶頸邏輯進行診斷:

圖片

所上圖所示,一次調用鏈作為一個 Trace,存在一個唯一的 TraceId,該 Trace 其中包含多個 Span,分別代表調用了下游的多個服務,其分別有一個對應的 SpanId 信息。通過上圖,就可以知道一次請求所經過的多個服務(該處假設一個下游服務對應一個 Span,有的鏈路追蹤系統可能會有差異)其所經歷的耗時情況,從而對應用耗時瓶頸進行定位和做對應的性能優化。

但在分佈式微服務領域,由於調用鏈路複雜,涉及跨機器甚至跨機房,由於一般的 Tracing 系統只能對主流開源軟件框架中的核心方法進行埋點,當耗時位置出現在 Tracing 埋點缺失的用户業務邏輯時,在最終的調用鏈中會出現一段較長的耗時無法對應到具體的代碼執行方法,從而導致無法對業務邏輯耗時進行準確的判斷。

具體 Case 可見如下所示代碼:

public String demo() throws SQLException {

    // 此處耗時1000ms,模擬其他業務耗時邏輯
    take1000ms(1000);
    // SQL 查詢執行操作
    stmt = conn.createStatement();
    ResultSet rs = stmt.executeQuery("SELECT * FROM table");

    return "Hello ARMS!";
}

private void take1000ms(long time) {
  try {
    Thread.sleep(time);
  } catch (InterruptedException e) {
    e.printStackTrace();
  }
}

在上述代碼邏輯中,第 6~7 行為數據庫連接相關的執行邏輯,這類邏輯一般主流的 Tracing 系統都會對其進行埋點覆蓋,但第 4 行的具體客户業務耗時,一般都由缺失對應的監控埋點,導致其耗時最終都被統計在了上一層入口 Spring Boot 方法 demo 中。

其對應最終在 Tracing 調用鏈中展示形式可能類似於下圖所示,通過 Tracing 調用鏈僅能知道第一層的外部接口耗時以及其中包含的知名軟件框架執行邏輯耗時情況,其中灰色陰影部分為 Tracing 系統埋點未覆蓋的用户業務邏輯代碼部分,作為監控盲區,其實際耗時未知,對線上性能問題排查造成不少的阻礙:

圖片

上述問題在企業用户中很常見,很多時候只能望其心嘆,束手無策!

解決方案

針對上述 Tracing 系統埋點缺失情況下的慢調用鏈耗時診斷問題,據筆者瞭解到的,目前業界相關的解決方案很少,熟悉 Arthas 的同學可能會提到其中的 trace 命令[1],確實其在一定程度上可以通過手工的方式在一些可以穩定復現的簡單場景慢調用鏈中排查相關慢調用鏈具體耗時位置。但是其侷限性也較為明顯:

  • 作用範圍有限

僅支持穩定復現場景的慢調用診斷,對於有觸發垃圾回收、資源爭搶、網絡問題等不易復現場景下的慢調用問題難以進行問題排查。

  • 使用門檻高

在實際的生產場景中,調用鏈可能會很複雜,必須對業務代碼非常熟悉的情況下,手動對特定的業務方法執行 trace 命令才能實現對請求耗時進行監控,如果對業務方法執行不熟悉或者是一些複雜的異步調用場景難以利用該工具進行問題排查。

  • 排查成本高

針對單跳簡單業務場景的慢調用使用該工具確實能進行相關問題排查,但是在跨應用多跳複雜業務場景下,排查過程就會變得很麻煩。不僅需要藉助一些 APM 工具先定位具體慢調用所在的應用實例,而且對於業務調用方法棧很深的場景下,需要逐層逐層地執行相關命令,一步步監控才有可能找到問題源頭。

綜上所述, Arthas 的 trace 命令可以作用在一些簡單的慢調用場景下,但對複雜場景下的慢調用鏈排查就顯得心有餘而力不足了!

為此,阿里雲 ARMS 團隊聯合阿里巴巴 Dragonwell 團隊通過持續剖析技術能夠幫助用户較好地還原調用鏈方法棧信息從而較好地解決這類 Tracing 監控盲區問題。

ARMS 持續剖析能力

作為國內知名的 APM 工具,ARMS 除了提供了 Tracing 和 Metrics 以及 Logging 相關業務主流的可觀測解決方案,另外也提供了開箱即用的持續剖析解決方案(Continuous Profiling,CP)。持續剖析是通過動態實時採集應用程序 CPU/ 內存等資源申請的堆棧信息,來幫助監測和定位應用程序的性能瓶頸。ARMS 目前提供的持續剖析能力這個架構如下圖所示:

圖片

在端側,通過 Java Agent 技術無侵入地在提供其他可觀測能力的基礎上,也提供了持續剖析數據採集能力。然後在服務端針對所採集的數據進行分析處理,最後在控制枱中為用户提供了開箱即用包含:CPU 診斷、內存診斷以及代碼熱點功能。

CPU & 內存診斷

火焰圖對於很多排查過應用性能問題的讀者肯定不陌生,通過觀察火焰圖中是否有寬頂,來定位應用的性能問題。對很多研發人員來説,上述説的火焰圖一般是指 CPU 熱點火焰圖。其表示的是一段時間內應用中執行了 CPU 的方法耗時情況。ARMS 提供的 CPU & 內存診斷功能在開源持續剖析 Async Profiler[2]基礎上支持在低開銷條件下常態化採集應用 CPU & 內存申請方法棧信息,支持簡單高效地常態化監控生產場景應用 CPU & 內存申請情況,告別利用開源工具難以常態化開啓,容易錯過不易復現問題場景的情況。

圖片

代碼熱點

説完 CPU & 內存診斷,有的讀者可能會問,是不是利用 CPU 診斷對應的方法棧火焰圖就可以幫助解決 Tracing 系統監控盲區問題幫助排查慢調用鏈呢?答案是否定的!因為 CPU診斷是通過定時抓取在 CPU 執行的執行線程的方法棧信息然後轉換為火焰圖。

而軟件程序中線程的狀態除了在 CPU 上執行的 Running 狀態(也叫做 On-CPU),還有 Blocked、Waiting 等其他狀態(統稱為 Off-CPU),而一個慢調用鏈往往是多種線程狀態疊加導致最終呈現出來的耗時長。因此 CPU 火焰圖針對慢調用鏈場景作用比較有限。

那有沒有一種火焰圖技術不僅可以用來描述 On-CPU,還能包含 Off-CPU 內容呢?那就不得不提到牆鍾火焰圖(Wallclock)了。其實現原理並不複雜,就是以固定頻率在應用所有線程中選一組線程採集其當前時刻的方法棧信息,通過聚合處理繪製出對應的火焰圖。像 Async Profiler 也提供了相關能力。

本文的主角代碼熱點即是在開源 Async Profiler 牆鍾能力的基礎上,通過關聯調用鏈中的 TraceId & SpanId 信息提供了調用鏈級別的 On & Off-CPU 火焰圖,可有效對 Tracing 的監控盲區細節進行還原,幫助用户診斷各類常見的慢調用鏈問題。具體過程如下圖所示,通過在線程創建 Span 開始時刻和結束時刻進行 TraceId & SpanId 信息關聯或關聯取消,讓最終產生的牆鍾方法棧快照 Sample 中包含相關信息,然後通過對最終的持續剖析數據進行處理和分析,還原出對應調用鏈有關的牆鍾火焰圖來幫助定位慢調用鏈問題:

圖片

核心特點

當前 ARMS 提供的持續剖析能力相比於其他的慢調用鏈診斷工具或者開源持續剖析工具具有以下特點:

  • 開銷低

通過基於 Trace 過程的自動採樣、關聯採樣率進行牆鍾剖析等措施,目前 ARMS 提供的持續剖析產品能力 CPU 開銷在 5%,堆外內存開銷 50M 左右,GC 額外開銷不明顯,能在生產環境常態化開啓。

  • 粒度細

除了應用級的 CPU &內存熱點外,還通過關聯 TraceId & SpanId 信息提供針對調用鏈級的方法棧信息,可有效幫助診斷慢調用鏈問題。

  • 安全可靠,簡單高效

開源的一些持續剖析技術,比如利用 Arthas 生成 CPU火焰圖(底層也是依賴 Async Profiler),由於一般都是即用即開,用完關閉,就算有技術風險,也不容易發現。在產品研發過程中,我們還是發現了很多開源技術比如 Async Profiler 持續剖析過程使用的風險問題。比如內存剖析可能引起應用 Crash #694[3],牆鍾火焰圖可能造成線程長時間阻塞 #769[4]等。通過修復這些問題讓我們產品能力更加安全可靠。除了安全,ARMS 提供的持續剖析能力常態化開啓後數據自動保存7天,讓用户不錯過每一次慢調用鏈的診斷現場。

利用代碼熱點排查慢調用鏈

開啓代碼熱點

  1. 登錄 ARMS 控制枱,在左側導航欄選擇應用監控 > 應用列表。
  2. 在應用列表頁面頂部選擇目標地域,然後單擊目標應用名稱。
  3. 在左側導航欄中單擊應用設置,然後單擊自定義配置頁籤。
  4. 開啓 CPU & 內存熱點總開關後,開啓代碼熱點開關並配置所需開啓的應用實例的IP地址或者一組實例所屬的網段地址。
  5. 在頁面底部單擊保存。

通過接口調用查看代碼熱點數據

  1. 登錄 ARMS 控制枱,在左側導航欄選擇應用監控 > 應用列表。
  2. 在應用列表頁面頂部選擇目標地域,然後單擊目標應用名稱。
  3. 在左側導航欄中單擊接口調用,並在頁面右側選擇目標接口,然後單擊調用鏈查詢頁籤。
  4. 在調用鏈查詢頁簽上單擊目標 TraceId 鏈接。
  5. 在詳情列中單擊放大鏡圖標,首先,可以單擊方法棧頁籤,看一下使用 Tracing 工具所展示的方法棧信息,可以看到其中僅包含了 MariaDB 相關的執行邏輯,而其前部的業務耗時並沒有被記錄。

圖片

  1. 接着,單擊代碼熱點頁籤,可以在右側的火焰圖中看到除了 MariaDB 相關方法棧(對應下圖右側火焰圖中的最右測較尖的火苗),還包含了 java.lang.Thread.sleep() 相關的 990ms 耗時(由於持續剖析基於採樣方式獲取線程方法棧,可能會存在些許偏差)。

圖片

圖中左側為本次調用中所涉及的所有方法所耗時情況列表,右側為對應方法所有方法棧信息所繪製的火焰圖。其中,Self 列展示了方法自身耗時。作為排查具體的熱點代碼邏輯,可以通過重點關注 Self 這一列或者直接看右側火焰圖中底部的較寬火苗從中定位到高耗時的業務方法,較寬火苗其是引發上層耗時高的根源,一般是系統性能的瓶頸所在,例如上圖中的 java.lang.Thread.sleep() 方法。其他更多使用細節可以參考該功能相關用户文檔[5]。

相關鏈接:

[1] trace 命令

https://arthas.aliyun.com/en/doc/trace.html

[2] Async Profiler

https://github.com/async-profiler/async-profiler

[3] #694

https://github.com/async-profiler/async-profiler/issues/694

[4] #769

https://github.com/async-profiler/async-profiler/issues/769

[5] 用户文檔

https://help.aliyun.com/zh/arms/application-monitoring/user-g...

作者:鋮樸、義泊

原文鏈接

本文為阿里雲原創內容,未經允許不得轉載。

user avatar coderleo 頭像 light_5cfbb652e97ce 頭像 yangyaya 頭像 aixiaodeludan_bqazwx 頭像
4 位用戶收藏了這個故事!

發佈 評論

Some HTML is okay.