我們都知道，MySQL 中的錯(cuò)誤日志，慢查詢?nèi)罩究梢詭湍憧焖俣ㄎ粏栴}。
但有時(shí)候，日志記錄的信息過少，或者是你感興趣信息被沒有被記下來，有時(shí)候又記錄了過多問題，大量無效信息干擾你排查問題。
因此，這篇文章介紹一種新的思路——探針技術(shù)，這種技術(shù)可以在不影響 MySQL 運(yùn)行，不破現(xiàn)場環(huán)境的前提下，在系統(tǒng)中的關(guān)鍵節(jié)點(diǎn)插入一些探針來收集信息。
理論上，探針可以插入 MySQL 或者 Linux 內(nèi)核任意函數(shù)進(jìn)出口，輕松訪問參數(shù)等其他詳細(xì)信息，資源損失很少，一旦移除探針后沒有任何損失。就像醫(yī)生給病人拍片子一樣，在不影響病人健康前提下，實(shí)時(shí)觀察病人體內(nèi)情況，為分析病因提供依據(jù)和支撐。
這篇文章介紹的探針像調(diào)試程序時(shí)候打斷點(diǎn)一樣，只不過打斷點(diǎn)是有交互的，同時(shí)是以字節(jié)碼形式運(yùn)行在內(nèi)核虛擬機(jī)(BPF)中的。
異常（exception） 就是控制流中的突變，用來響應(yīng)處理器狀態(tài)中的某些變化。理解異常有助于理解探針技術(shù)。下圖 所示處理器在執(zhí)行時(shí)執(zhí)行時(shí)，發(fā)生了一個(gè)重要的變化，我們把它稱為事件（event）。事件可能與當(dāng)前指令直接相關(guān)，如缺頁異常，算術(shù)溢出，嘗試除以 0 。也有可能無關(guān)如定時(shí)器產(chǎn)生信號，I/O 完成。在任何情況下處理器通過異常表進(jìn)行一個(gè)間接過程調(diào)用到專門的異常處理程序來處理。
異常可以分成四類：中斷（interrupt)， 陷阱（trap），故障（fault）和終止（abort）。
中斷是異步發(fā)生的，是來自處理器外部 I/O （鼠標(biāo)，鍵盤，網(wǎng)卡等）設(shè)備信號的結(jié)果。硬件中斷不是由任何一條專門的指令造成，從這個(gè)意義講它是異步的。剩下的異常類型（陷阱，故障，終止）是同步發(fā)生的，是執(zhí)行當(dāng)前指令的結(jié)果。我們把這種指令稱為故障指令。
陷阱是有意的異常，是程序員“主動(dòng)”觸發(fā)的，就像是自己在代碼埋下一個(gè)陷阱一樣。陷阱最常見的用戶是進(jìn)程發(fā)起系統(tǒng)調(diào)用，通過 INT 從用戶態(tài) trap 進(jìn)內(nèi)核態(tài)。
故障由錯(cuò)誤情況引起，能夠被故障處理程序修正。當(dāng)故障發(fā)生時(shí)，處理器講控制轉(zhuǎn)移給故障處理程序。例如當(dāng)缺頁異常發(fā)生時(shí)，故障處理程序可以從磁盤中間對應(yīng)的頁 swap 進(jìn)物理內(nèi)存。
終止，是不可恢復(fù)的致命錯(cuò)誤造成的結(jié)果，通常是一些硬件錯(cuò)誤。程序員平常調(diào)試代碼時(shí)，給程序添加斷點(diǎn)，讓程序在我們想要的地方停住。調(diào)試器能夠隨心所欲控制程序運(yùn)行，主要靠軟件中斷。軟件斷點(diǎn)在 X86 系統(tǒng)中就是指令 INT 3。當(dāng)程序執(zhí)行到 INT 3 指令時(shí)，會引發(fā)軟件中斷。這就是上文提到的陷阱。不同于我們在 Visual Studio 和 GDB 中交互式的斷點(diǎn)，如果程序在 trap 發(fā)生時(shí)，自動(dòng)執(zhí)行預(yù)定義和 handle 記錄和統(tǒng)計(jì)運(yùn)行情況，不影響程序的正常運(yùn)行，達(dá)到觀察 MySQL 的目的。
為了捕捉程序運(yùn)行情況，我們在程序中設(shè)置一些 “ 陷阱 ”，并設(shè)置處理程序，我們稱之為探針。有的探針是在代碼中預(yù)定義的，有的是在運(yùn)行時(shí)動(dòng)態(tài)添加的。
靜態(tài)探針是事先在程序中定義好，并編譯到程序或者內(nèi)核的探針。
靜態(tài)探針只有被開啟時(shí)才會運(yùn)行，不開啟就不會運(yùn)行，常見的靜態(tài)探針包括內(nèi)核中的跟蹤點(diǎn)（tracepoints）和 USDT（Userland Statically Defined Tracing）探針。tracepoints 在代碼中埋下鉤子，在運(yùn)行時(shí)調(diào)用相連接的探針。
它有“打開”（已連接探針）和“關(guān)閉”（未連接探針）兩種狀態(tài)。
當(dāng)跟蹤點(diǎn)處于“關(guān)閉”狀態(tài)時(shí)，它沒有任何作用，只增加微小的時(shí)間損失（檢查分支的條件）和空間損失。當(dāng)跟蹤點(diǎn)為“ 打開”時(shí)，每次在調(diào)用者的執(zhí)行上下文中執(zhí)行跟蹤點(diǎn)時(shí)，都會調(diào)用相連接的探針。探針函數(shù)執(zhí)行完后，將返回到調(diào)用方。USDT和tracepoint類似，只不過是用戶態(tài)的，在代碼中插入DTRACE_PROBE()即可。
動(dòng)態(tài)探針是應(yīng)用程序沒有定義，在程序運(yùn)行時(shí)動(dòng)態(tài)添加的探針。
動(dòng)態(tài)探針類似于異常處理機(jī)制，當(dāng)系統(tǒng)產(chǎn)生一個(gè)異常，就會跳轉(zhuǎn)去執(zhí)行對應(yīng)的 handle。動(dòng)態(tài)探針會在函數(shù)入口和出口插入一些斷點(diǎn)，程序執(zhí)行到斷點(diǎn)時(shí)候會去執(zhí)行對應(yīng)的 handle，從而達(dá)到觀測應(yīng)用程序的目的。這里的中斷是指 trap（陷阱)，在X86體系是int3指令。
KProbes 是 Linux 內(nèi)核探針，可以用于監(jiān)視生產(chǎn)系統(tǒng)中的事件。您可以使用它來解決性能瓶頸，記錄特定事件，跟蹤問題等。
KProbes 能實(shí)時(shí)在內(nèi)核代碼中插入中斷指令，雖然這聽上去有點(diǎn)不可思議，實(shí)際上 KProbes 做了很多安全性保證，例如 stop_machine 用于確保其他CPU在被修改時(shí)停止執(zhí)行。
實(shí)際上 kprobes 最大風(fēng)險(xiǎn)是給一些調(diào)用十分頻繁的函數(shù)加上探針，如在網(wǎng)絡(luò)模塊中，頻繁中斷可能造成一定的性能風(fēng)險(xiǎn)。KProbe需要定義 pre-handler 和 post-handler，當(dāng)被探測的指令要被執(zhí)行時(shí)，先執(zhí)行pre-handler程序。同樣，當(dāng)被探測指令執(zhí)行之后立即執(zhí)行post-handler。
uprobes 是Linux提供用戶態(tài)的動(dòng)態(tài)探針，合并于2012年7月發(fā)布的 Linux 3.5 內(nèi)核中。uprobes 和 kprobes 十分相似，用于用戶態(tài)。
BPF(Berkeley Packet Filter) 最早開發(fā)在 BSD 操作系統(tǒng)中，是 TCP/IP 包過濾的工業(yè)標(biāo)注，被 tcpdump 使用。
它的工作方法有點(diǎn)特別：用戶自定義包過濾表達(dá)式，然后注入內(nèi)核中的 BPF 中運(yùn)行，這樣的好處就是在內(nèi)核進(jìn)行過濾而不是將包拷貝到用戶態(tài)，避免大量數(shù)據(jù)從內(nèi)核態(tài)拷貝到用戶態(tài)，因此具有較好的性能。
后來出現(xiàn)了eBPF(extend BPF), eBPF 有自己的語言，用戶自己編寫程序編譯后通過 BPF 調(diào)用注入到內(nèi)核的 BPF 虛擬機(jī)中運(yùn)行，可以安全訪問內(nèi)核內(nèi)存，它使得內(nèi)核變成可編程。運(yùn)行在內(nèi)核中因?yàn)椴恍枰褦?shù)據(jù)拷貝到用戶空間往往具有比較高的性能，因此 BPF 被很多性能追蹤工具使用。
上文介紹了相關(guān)的技術(shù)背景，接下來介紹使用追蹤工具觀測 bpftrace, 它是一種使用 BPF 進(jìn)行性能分析的前端工具，使用起來很方便，類似與 awk 語言。由于 MySQL 是運(yùn)行在用戶態(tài)態(tài)的，要追蹤 MySQL 本身只能使用** USDT** 和** uprobes**。
MySQL 在系統(tǒng)中一些關(guān)鍵位置定義了 USDT, 參考文檔 mysqld DTrace Probe Reference(DTrace 是 Solaris 中的動(dòng)態(tài)追蹤工具，bpftrace 是 Linux 版本的 DTrace) 下面展示一下記錄追蹤到的慢查詢的腳本。
BEGIN{ printf("Tracing mysqld queries slower than %d ms. Ctrl-C to end.\n", $1); printf("%-10s %-6s %6s %s\n", "TIME(ms)", "PID", "MS", "QUERY");}
usdt:/usr/sbin/mysqld:mysql:query__start{ @query[tid] = str(arg0); @start[tid] = nsecs;}
usdt:/usr/sbin/mysqld:mysql:query__done/@start[tid]/{ $dur = (nsecs - @start[tid]) / 1000000; if ($dur > $1) { printf("%-10u %-6d %6d %s\n", elapsed / 1000000, pid, $dur, @query[tid]); } delete(@query[tid]); delete(@start[tid]);}
解讀一下 ** BEGIN** 是這個(gè)腳本剛開始運(yùn)行時(shí)候的執(zhí)行的，打印一些提示信息。usdt:/usr/sbin/mysqld:mysql:query__start 是給** query__start ** 這個(gè)函數(shù)加的探針，當(dāng)程序執(zhí)行到這里時(shí)，記錄一下第一個(gè)參數(shù) arg0(query), 和當(dāng)前時(shí)間時(shí)間戳，并把這些信息保存在 BPF 的 map 中。query__done 探針被執(zhí)行時(shí)，記錄當(dāng)前時(shí)間，減去開始時(shí)間（從 BPF 的 map 中獲取），就是這個(gè)查詢的花費(fèi)時(shí)間，如果超過閾值就打印出來。如果你會說 MySQL 有慢查詢?nèi)罩景。贿^這里優(yōu)勢是不需要重啟 MySQL，可以實(shí)時(shí)修改閾值。而且 usdt 在高級版本MySQL 會被移除，同時(shí)需要編譯時(shí)設(shè)置參數(shù) -DENABLE_DTRACE=1 才能支持 usdt。
不同與 usdt 需要事先在代碼中設(shè)置觀測點(diǎn)，uprobes 可以在程序中動(dòng)態(tài)添加，可以插入到任意函數(shù)的進(jìn)口和出口位置。下面展示是使用 uprobes 探針對 dispatch_command 進(jìn)行追蹤，打印出慢查詢語句。
BEGIN{ printf("Tracing mysqld queries slower than %d ms. Ctrl-C to end.\n", $1); printf("%-10s %-6s %6s %s\n", "TIME(ms)", "PID", "MS", "QUERY");}
uprobe:/usr/sbin/mysqld:*dispatch_command*{ $COM_QUERY = 3; if (arg2 == $COM_QUERY) { @query[tid] = str(*arg1); @start[tid] = nsecs; }}
uretprobe:/usr/sbin/mysqld:*dispatch_command*/@start[tid]/{ $dur = (nsecs - @start[tid]) / 1000000; if ($dur > $1) { printf("%-10u %-6d %6d %s\n", elapsed / 1000000, pid, $dur, @query[tid]); } delete(@query[tid]); delete(@start[tid]);}
運(yùn)行一下 這里使用參數(shù) 10，表示慢查詢閾值是 10 ms.
sudo ./mysql_uprobe_slow.bt 10Attaching 3 probes...Tracing mysqld queries slower than 10 ms. Ctrl-C to end.TIME(ms) PID MS QUERY35976 1083 742 select employees.first_name, employees.last_name, titles.title 93145 1083 224 select * from employees125348 1083 1727 select * from salaries
bpftrace 還提供了直方圖工具，可以將所有查詢耗時(shí)記錄下來，最后打印出耗時(shí)分布直方圖。
#!/usr/bin/bpftrace
BEGIN{ printf("Tracing MySQL query... Hit Ctrl-C to end.\n");}
uprobe:/usr/sbin/mysqld:*dispatch_command*{ @start[tid] = nsecs;}
uretprobe:/usr/sbin/mysqld:*dispatch_command*/@start[tid]/{ @usecs = hist((nsecs - @start[tid]) / 1000000); delete(@start[tid]);}
END{ clear(@start);}
sudo ./histo.bt Attaching 4 probes...Tracing MySQL query... Hit Ctrl-C to end.^C
@usecs: [0] 10 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|[1] 0 | |[2, 4) 0 | |[4, 8) 0 | |[8, 16) 0 | |[16, 32) 0 | |[32, 64) 0 | |[64, 128) 0 | |[128, 256) 1 |@@@@@ |[256, 512) 1 |@@@@@ |[512, 1K) 0 | |[1K, 2K) 1 |@@@@@ |
除了本文展示的 USDT 和 UProbes 兩種探針，展示例子比較簡單，還可以同時(shí)插入多個(gè)探針，使用 BPF 的 map 來共享信息，達(dá)到更強(qiáng)的觀測能力。
除了這兩種探針，還可以使用 tracepoints 和 KProbe 來分析內(nèi)核態(tài)，例如網(wǎng)絡(luò)運(yùn)行情況，磁盤 I/O 情況，當(dāng)然這需要你對程序有一定熟悉，要不然不知道這些探針加到哪個(gè)地方好。
PS：歡迎在留言區(qū)留下你的觀點(diǎn)，一起討論提高。如果今天的文章讓你有新的啟發(fā)，歡迎轉(zhuǎn)發(fā)分享給更多人。
Java后端編程交流群已成立
公眾號運(yùn)營至今，離不開小伙伴們的支持。為了給小伙伴們提供一個(gè)互相交流的平臺，特地開通了官方交流群。掃描下方二維碼備注 進(jìn)群 或者關(guān)注公眾號 Java后端編程 后獲取進(jìn)群通道。
—————END—————
最近面試BAT，整理一份面試資料《Java面試BAT通關(guān)手冊》，覆蓋了Java核心技術(shù)、JVM、Java并發(fā)、SSM、微服務(wù)、數(shù)據(jù)庫、數(shù)據(jù)結(jié)構(gòu)等等。
獲取方式：關(guān)注公眾號并回復(fù) java 領(lǐng)取，更多內(nèi)容陸續(xù)奉上。
明天見(??ω??)??
