天天看點

node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

作者:JAVA我要發大财
node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

背景和行文目的

在做 node 或者其他語言的軟體開發時,是否有以下經曆:

  1. 測試環境一切正常,發到生産環境後,出現詭異問題且難以定位
  2. 不同機器、不同容器上,某些邏輯呈現不同的結果,如時區、 host
  3. 對于時好時壞的玄學問題,束手無策,沒有完整地解決思路,無頭蒼蠅般的各種嘗試,效率低下
  4. 遇到坑,習慣搜網友解決方案,然後試很多方案,都不能解決問題,此時就會感覺頭皮發麻

我相信,上述我說的經曆,大多數人都會有所共鳴。本文,我将盡可能地把我所學的動态追蹤技術分享給大家。

文章内容如下所示:

  1. 介紹 Dynamic Trace 的概念、優勢、原理和用法(我們需要掌握的那部分)
  2. 通過 demo , 展示 Dynamic Trace 技術的強大
  3. 實戰示範: 搭建 node 性能監控 easy-monitor 和建構 node 應用,構造詭異故障,并闡述如何用 Dynamic Trace 去精确快速定位
  4. 分享代碼: 會把實戰示範的代碼放到 github 上,大家可以 clone 自行去體驗
  5. 動态追蹤技術的未來: 介紹下目前最領先的 Dynamic Trace 方案
  6. 總結: 做一個精簡的總結
  7. 附: 其他内容

話不多說,直接開整。

動态追蹤技術

是什麼

這裡我把章亦春大佬的原話引用過來:

動态追蹤技術其實是一種後現代的進階調試技術。它可以幫助軟體工程師以非常低的成本,在非常短的時間内,回答一些很難的關于軟體系統方面的問題,進而更快速地排查和解決問題。

優勢

優勢如下:

  • 随時随地,按需采集
  • 基于作業系統核心實作,性能損耗極小

原理

動态追蹤的事件源根據事件類型不同,主要分為靜态探針、動态探針以及硬體事件,其原理如下圖所示:

node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

看不懂也正常,我也看不懂,不過會用進行,就跟你不會造車,但你可以把車開得很溜。

簡單點說,就是在 linux 中,程序不能直接通路硬體裝置,當程序需要通路硬體裝置時,如 IO 操作,必須由使用者态切換至核心态,然後通過作業系統調用硬體裝置。 是以可以通過跟蹤程序産生的系統調用,來獲得參數、傳回值、執行時間,進而完成動态追蹤。

我們用得多的是動态探針,它可以讓我們實時分析線上運作的程式。

用法

動态追蹤工具有 strace 、 dtruss 、 systemtap 、 perf 、 dtrace 、 eBPF 等,我這邊使用的是 strace 和 dtruss 。

也就是 linux 環境使用 strace , macos 系統使用 dtruss 。

strace 的主要參數說明如下表所示:

參數名 含義
-v 輸出所有的系統調用,一些調用關于環境變量、狀态、輸入輸出等調用由于使用頻繁,預設不輸出
-s SIZE 指定輸出的字元串的最大長度,預設為32,檔案名一直全部輸出
-p PID 跟蹤指定的程序pid
-c 統計每一系統調用的所執行的時間,次數和出錯的次數等
-d 輸出strace關于标準錯誤的調試資訊
-f 跟蹤由fork調用所産生的子程序
-o filename 将strace的輸出寫入檔案filename
-e trace=network 跟蹤與網絡有關的所有系統調用
-e trace=file 隻跟蹤有關檔案操作的系統調用

以上參數用得最多的就是 -v 、 -s 、 -p 、 -c 。

比如我現在想看部署在 linux 上的 node 應用運作時的資訊,那我就可以執行以下指令

strace -p 8000 -v -s 2048
複制代碼           

參照參數說明表解讀上述指令: 跟蹤 pid 為 8000 的程序( node 應用),輸出所有的運作時系統調用,同時指定字元串最大長度為 2048 。

同理, dtruss 的主要參數說明如下表所示:

參數名 含義
-a 輸出所有詳細資訊
-p PID 跟蹤指定的程序pid
-c 輸出系統調用計數
-d 輸出相對時間
-e 輸出運作時間
-f 跟蹤由fork調用所産生的子程序
-t 僅檢查此系統調用
-s 輸出堆棧回溯
-o 輸出cpu時間

以上參數用得最多的就是 -p 、 -c 、 e 、 f 。

注意: 在 macos 系統上使用 dtruss , 要先執行 csrutil disable

指令行例子就不舉了,和 strace 是一樣的道理。

demo 示範

場景: 大家在做開發的時候,有的會遇到時區問題,比如說在我的機器上,時間是對的,但是在其他機器或者容器上,時間是不對的。然後你就很疑惑,開始搜,找到了所謂的執行下某個指令就好了。

思考: 你有沒有想過兩台機器的時間為什麼不一樣,是哪個環節出了問題,比如下面代碼在兩台機器上的輸出結果為什麼不同。

console.log(new Date().toLocaleString())
複制代碼           

如果你知道動态追蹤技術,那你就可以開啟 **透視眼 ** , 看看在系統核心層面,上面代碼究竟做了什麼事情。

動态追蹤:

參照 dtruss 參數表,我們執行如下指令

sudo dtruss -of node time.js
複制代碼           

控制台如下圖:

node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

輸出了非常多的東西,沒關系,我們直接搜 toLocaleString 關鍵詞,結果如下:

node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

會發現圖中綠色框中 read(0x14, "console.log(new Date().toLocaleString())\0", 0x28) 出現了搜尋的關鍵詞, 這句表達式的字面含義是: 系統在讀取 time.js 中的内容。

我們順着上面語句往下閱讀,會發現如下圖所示重要語句:

node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

看到上面三個綠色框内容後,已經基本确定, new Date().toLocaleString() 傳回值, 是系統層面讀取 /etc/localtime 的内容。也就是說,這個問題的原因是不同機器的 /etc/localtime 不一樣

看到這你會明白:

  • 為什麼不同機器的傳回值會不一樣
  • 為什麼網上給的時區解決方案是和 /etc/localtime 有關的

上面這個小 demo ,可以讓我們更好的感覺用 Dynamic Trace 所帶來的巨大好處,所有的代碼在核心層面都是裸奔的,它可以幫你更好的定位稀奇古怪的問題。

實戰示範

為了更友善的示範,我這邊所有操作都是在 mac 電腦進行的。 我将做以下操作

  • 搭建 easy-monitor 環境
  • 啟動一個 egg 應用
  • 制造制造問題
  • 結合 easy-monitor 用 Dynamic trace 進行有序精準定位
  • 實戰總結

搭建 easy-monitor 環境

花了 20 分鐘左右,搭建好一個本地 easy-monitor 環境,項目結構如下圖所示:

node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

在官網文檔的情況下做了一點點優化,優化如下:

  1. 将監控子產品整合成 monorepo 形式,使用 pnpm 管理,上 workspace
  2. 采用 turbo ,快速拉起所有包的開發模式

搭建好,一鍵啟動開發環境,終端如下圖所示:

node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

web 控制台如下圖所示:

node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

啟動一個 egg 應用

這個按照官網文檔建立一個 egg 應用, 然後按照下圖所示進行配置即可

node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

過程非常簡單,在上一個過程,我已經用 turbo 一起啟動 egg 應用了。

制造問題

簡單化, 我們寫一個 node 服務, 加一個 bug 代碼。代碼如下:

const Controller = require('egg').Controller;
const fs = require('fs');

async function read() {
  const data = await fs.readFileSync(__dirname + '/home.js', 'utf-8');
  if (data) read();
}

class CpuController extends Controller {
  async index() {
    const { ctx } = this;
    ctx.body = 'cpu will be 90%';
    read();
  }
}

module.exports = CpuController;
複制代碼           

通路路由 /cpu 的時候, node 服務進行讀取 home.js 檔案死循環狀态。 此時 觀察 easy-monitor cpu 狀态。如下圖所示:

node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

會發現, cpu 在逐漸升高,然後開始報警,遇到這種問題,如何快速精準定位呢?

Dynamic trace 精準定位

在 easy-monitor 上發現 cpu 持續升高,居高不下時。心裡有一個基調,那就是線上可能出問題了,此時,先冷靜,然後進行問題定位,步驟如下

  1. 确定使 cpu 居高不下的程序,這個通過 easy-monitor 或者 top 指令都可以。
  2. 拿到程序 pid 後,通過下面指令,來動态追蹤,該程序運作時資訊和熱點函數。
sudo dtruss -c -p 26514
複制代碼           

執行 10 秒後,退出,檢視輸出内容,如下圖所示:

node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

會發現,目前服務,其 open 、 read 和 fstat64 調用次數非常多,心裡大概确定該問題和檔案操作有關,然後再細緻的看下輸出内容,如下圖所示:

node應用故障定位頂級技巧—動态追蹤技術「Dynamic Trace」

會發現,存在大量的讀取路徑 /Users/godkun/monitor/apps/egg-app/app/controller/home.js 的操作,分析到這,基本可以确定問題的原因之一了,那麼後面的事情就非常簡單。

快速查閱該部分代碼,發現存在隐藏的循序讀取邏輯,遂進行優化,優化後, easy-monitor 的性能監控顯示, cpu 立刻下降,且運作平穩。

實戰總結

我們構造了一個循環讀取檔案導緻 node 服務 cpu 居高不下的線上問題,然後結合 easy-monitor 做性能監控, 同時使用動态追蹤技術進行外科手術式精準定位線上問題,最後快速給出解決方案,整個過程有序高效。

可以這麼說, 動态追蹤 + easy-monitor 基本可以解決 node 服務遇到的所有疑難雜症。

分享代碼

實戰代碼連結: github.com/godkun/dyna…

代碼倉庫主要是将 easy-monitor 和 dynamic-trace 結合,在本地模拟各種問題場景,來學習、了解和掌握。

寫的比較急,目前還沒做 mysql 、 redis 的 docker 化,後面有空會更新上這個功能。

動态追蹤技術的未來

傳統工具

目前的動态追蹤工具,如 dtruss strace perf 等,都是誕生時間很久的工具了,在用的過程中,會發現有大量的無用輸出,會影響定位效率,這算是一個小小的缺點。

潛力工具

在動态追蹤工具中,有一個叫 eBPF , 它可以隻輸出某一行代碼活某一段代碼和系統互動的資訊,可以讓我們迅速定位哪裡出了問題,而不是面對一大堆輸出資訊,去閱讀、查找、判斷和定位。

未來 + 頂尖

目前動态追蹤領域,最厲害的工具應該是章亦春大佬開發的 xray ,但目前沒有開源,未來期待春哥開源 xray ,将動态追蹤能力拉滿,造福廣大程式員們。

總結

到此,本文即将完成,我們可以把動态追蹤技術想象成核磁共振。當你的應用出現問題的時候,無需停機、即刻對其做一個掃描,它可以讓你看到應用代碼在核心層面實時裸奔的畫面。

動态追蹤是 一種不限于 node 服務,可以定位所有服務線上故障的頂級技術。

這裡補一個内容,就是可能會有讀者問, easy-monitor 和 Dynamic Trace 有什麼差別,為什麼不能都用 easy-monitor ?

原因很簡單: easy-monitor 隻能到 JavaScript 的級别,而 Dynamic Trace 是直接到最底層,也就是作業系統的層面。是以,我們既需要 easy-monitor ,也更需要 Dynamic Trace

繼續閱讀