絕了！這個MySQL故障定位方法太好用了
我們都知道，MySQL 中的錯誤日志，慢查詢?nèi)罩究梢詭湍憧焖俣ㄎ粏栴}。
但有時候，日志記錄的信息過少，或者是你感興趣信息被沒有被記下來，有時候又記錄了過多問題，大量無效信息干擾你排查問題。
因此，這篇文章介紹一種新的思路——探針技術，這種技術可以在不影響 MySQL 運行，不破現(xiàn)場環(huán)境的前提下，在系統(tǒng)中的關鍵節(jié)點插入一些探針來收集信息。
理論上，探針可以插入 MySQL 或者 Linux 內(nèi)核任意函數(shù)進出口，輕松訪問參數(shù)等其他詳細信息，資源損失很少，一旦移除探針后沒有任何損失。就像醫(yī)生給病人拍片子一樣，在不影響病人健康前提下，實時觀察病人體內(nèi)情況，為分析病因提供依據(jù)和支撐。
Part1 探針的原理
這篇文章介紹的探針像調(diào)試程序時候打斷點一樣，只不過打斷點是有交互的，同時是以字節(jié)碼形式運行在內(nèi)核虛擬機(BPF)中的。
一、異常
異常（exception） 就是控制流中的突變，用來響應處理器狀態(tài)中的某些變化。理解異常有助于理解探針技術。下圖 所示處理器在執(zhí)行時執(zhí)行時，發(fā)生了一個重要的變化，我們把它稱為事件（event）。事件可能與當前指令直接相關，如缺頁異常，算術溢出，嘗試除以 0 。也有可能無關如定時器產(chǎn)生信號，I/O 完成。在任何情況下處理器通過異常表進行一個間接過程調(diào)用到專門的異常處理程序來處理。
異?？梢苑殖伤念悾?nbsp;中斷（interrupt)， 陷阱（trap），故障（fault）和終止（abort）。
中斷是異步發(fā)生的，是來自處理器外部 I/O （鼠標，鍵盤，網(wǎng)卡等）設備信號的結(jié)果。 硬件中斷不是由任何一條專門的指令造成，從這個意義講它是異步的。剩下的異常類型（陷阱，故障，終止）是同步發(fā)生的，是執(zhí)行當前指令的結(jié)果。我們把這種指令稱為故障指令。
陷阱是有意的異常，是程序員“主動”觸發(fā)的，就像是自己在代碼埋下一個陷阱一樣。 陷阱最常見的用戶是進程發(fā)起系統(tǒng)調(diào)用，通過 INT 從用戶態(tài) trap 進內(nèi)核態(tài)。
故障由錯誤情況引起，能夠被故障處理程序修正。 當故障發(fā)生時，處理器講控制轉(zhuǎn)移給故障處理程序。例如當缺頁異常發(fā)生時，故障處理程序可以從磁盤中間對應的頁 swap 進物理內(nèi)存。
終止，是不可恢復的致命錯誤造成的結(jié)果，通常是一些硬件錯誤。 程序員平常調(diào)試代碼時，給程序添加斷點，讓程序在我們想要的地方停住。調(diào)試器能夠隨心所欲控制程序運行，主要靠軟件中斷。軟件斷點在 X86 系統(tǒng)中就是指令 INT 3。當程序執(zhí)行到 INT 3 指令時，會引發(fā)軟件中斷。這就是上文提到的陷阱。不同于我們在 Visual Studio 和 GDB 中交互式的斷點，如果程序在 trap 發(fā)生時，自動執(zhí)行預定義和 handle 記錄和統(tǒng)計運行情況，不影響程序的正常運行，達到觀察 MySQL 的目的。
二、探針
為了捕捉程序運行情況，我們在程序中設置一些 “ 陷阱 ”，并設置處理程序，我們稱之為探針。有的探針是在代碼中預定義的，有的是在運行時動態(tài)添加的。
1. 靜態(tài)探針
靜態(tài)探針是事先在程序中定義好，并編譯到程序或者內(nèi)核的探針。
靜態(tài)探針只有被開啟時才會運行，不開啟就不會運行，常見的靜態(tài)探針包括內(nèi)核中的跟蹤點（tracepoints）和 USDT（Userland Statically Defined Tracing）探針。tracepoints 在代碼中埋下鉤子，在運行時調(diào)用相連接的探針。
它有“打開”（已連接探針）和“關閉”（未連接探針）兩種狀態(tài)。
當跟蹤點處于“關閉”狀態(tài)時，它沒有任何作用，只增加微小的時間損失（檢查分支的條件）和空間損失。當跟蹤點為“ 打開”時，每次在調(diào)用者的執(zhí)行上下文中執(zhí)行跟蹤點時，都會調(diào)用相連接的探針。探針函數(shù)執(zhí)行完后，將返回到調(diào)用方。USDT和tracepoint類似，只不過是用戶態(tài)的，在代碼中插入DTRACE_PROBE()即可。
2. 動態(tài)探針
動態(tài)探針是應用程序沒有定義，在程序運行時動態(tài)添加的探針。
動態(tài)探針類似于異常處理機制，當系統(tǒng)產(chǎn)生一個異常，就會跳轉(zhuǎn)去執(zhí)行對應的 handle。動態(tài)探針會在函數(shù)入口和出口插入一些斷點，程序執(zhí)行到斷點時候會去執(zhí)行對應的 handle，從而達到觀測應用程序的目的。這里的中斷是指 trap（陷阱)，在X86體系是int3指令。
KProbes 是 Linux 內(nèi)核探針，可以用于監(jiān)視生產(chǎn)系統(tǒng)中的事件。您可以使用它來解決性能瓶頸，記錄特定事件，跟蹤問題等。
KProbes 能實時在內(nèi)核代碼中插入中斷指令，雖然這聽上去有點不可思議，實際上 KProbes 做了很多安全性保證，例如 stop_machine 用于確保其他CPU在被修改時停止執(zhí)行。
實際上 kprobes 最大風險是給一些調(diào)用十分頻繁的函數(shù)加上探針，如在網(wǎng)絡模塊中，頻繁中斷可能造成一定的性能風險。KProbe需要定義 pre-handler 和 post-handler，當被探測的指令要被執(zhí)行時，先執(zhí)行pre-handler程序。同樣，當被探測指令執(zhí)行之后立即執(zhí)行post-handler。
uprobes 是Linux提供用戶態(tài)的動態(tài)探針，合并于2012年7月發(fā)布的 Linux 3.5 內(nèi)核中。uprobes 和 kprobes 十分相似，用于用戶態(tài)。
三、BPF
BPF(Berkeley Packet Filter) 最早開發(fā)在 BSD 操作系統(tǒng)中，是 TCP/IP 包過濾的工業(yè)標注，被 tcpdump 使用。
它的工作方法有點特別： 用戶自定義包過濾表達式，然后注入內(nèi)核中的 BPF 中運行 ，這樣的好處就是在內(nèi)核進行過濾而不是將包拷貝到用戶態(tài)，避免大量數(shù)據(jù)從內(nèi)核態(tài)拷貝到用戶態(tài)，因此具有較好的性能。
后來出現(xiàn)了eBPF(extend BPF), eBPF 有自己的語言，用戶自己編寫程序編譯后通過 BPF 調(diào)用注入到內(nèi)核的 BPF 虛擬機中運行，可以安全訪問內(nèi)核內(nèi)存，它使得內(nèi)核變成可編程。運行在內(nèi)核中因為不需要把數(shù)據(jù)拷貝到用戶空間往往具有比較高的性能，因此 BPF 被很多性能追蹤工具使用。
Part2 使用探針觀測MySQL
上文介紹了相關的技術背景，接下來介紹使用追蹤工具觀測 bpftrace, 它是一種使用 BPF 進行性能分析的前端工具，使用起來很方便，類似與 awk 語言。由于 MySQL 是運行在用戶態(tài)態(tài)的，要追蹤 MySQL 本身只能使用 ** USDT** 和** uprobes** 。
一、使用 USDT 觀測 MySQL
MySQL 在系統(tǒng)中一些關鍵位置定義了 USDT, 參考文檔 mysqld DTrace Probe Reference(DTrace 是 Solaris 中的動態(tài)追蹤工具，bpftrace 是 Linux 版本的 DTrace) 下面展示一下記錄追蹤到的慢查詢的腳本。
- #!/usr/bin/bpftrace
- 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]);
- }
二、使用 uprobes 觀測 MySQL
不同與 usdt 需要事先在代碼中設置觀測點，uprobes 可以在程序中動態(tài)添加，可以插入到任意函數(shù)的進口和出口位置。下面展示是使用 uprobes 探針對 dispatch_command 進行追蹤，打印出慢查詢語句。
- #!/usr/bin/bpftrace
- 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]);
- }
- sudo ./mysql_uprobe_slow.bt 10
- Attaching 3 probes...
- Tracing mysqld queries slower than 10 ms. Ctrl-C to end.
- TIME(ms) PID MS QUERY
- 35976 1083 742 select employees.first_name, employees.last_name, titles.title
- 93145 1083 224 select * from employees
- 125348 1083 1727 select * from salaries
- #!/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 |@@@@@ |
（左右滑動查看代碼）
結(jié)語
除了本文展示的 USDT 和 UProbes 兩種探針，展示例子比較簡單，還可以同時插入多個探針，使用 BPF 的 map 來共享信息，達到更強的觀測能力。
除了這兩種探針，還可以使用 tracepoints 和 KProbe 來分析內(nèi)核態(tài)，例如網(wǎng)絡運行情況，磁盤 I/O 情況，當然這需要你對程序有一定熟悉，要不然不知道這些探針加到哪個地方好。
