我們都知道，MySQL 中的錯(cuò)誤日志，慢查詢?nèi)罩究梢詭湍憧焖俣ㄎ粏?wèn)題。但有時(shí)候，日志記錄的信息過(guò)少，或者是你感興趣信息被沒(méi)有被記下來(lái)，有時(shí)候又記錄了過(guò)多問(wèn)題，大量無(wú)效信息干擾你排查問(wèn)題。因此，這篇文章介紹一種新的思路——探針技術(shù)，這種技術(shù)可以在不影響 MySQL 運(yùn)行，不破現(xiàn)場(chǎng)環(huán)境的前提下，在系統(tǒng)中的關(guān)鍵節(jié)點(diǎn)插入一些探針來(lái)收集信息。理論上，探針可以插入 MySQL 或者 Linux 內(nèi)核任意函數(shù)進(jìn)出口，輕松訪問(wèn)參數(shù)等其他詳細(xì)信息，資源損失很少，一旦移除探針后沒(méi)有任何損失。就像醫(yī)生給病人拍片子一樣，在不影響病人健康前提下，實(shí)時(shí)觀察病人體內(nèi)情況，為分析病因提供依據(jù)和支撐。
這篇文章介紹的探針像調(diào)試程序時(shí)候打斷點(diǎn)一樣，只不過(guò)打斷點(diǎn)是有交互的，同時(shí)是以字節(jié)碼形式運(yùn)行在內(nèi)核虛擬機(jī)(BPF)中的。異常（exception） 就是控制流中的突變，用來(lái)響應(yīng)處理器狀態(tài)中的某些變化。理解異常有助于理解探針技術(shù)。下圖 所示處理器在執(zhí)行時(shí)執(zhí)行時(shí)，發(fā)生了一個(gè)重要的變化，我們把它稱為事件（event）。事件可能與當(dāng)前指令直接相關(guān)，如缺頁(yè)異常，算術(shù)溢出，嘗試除以 0 。也有可能無(wú)關(guān)如定時(shí)器產(chǎn)生信號(hào)，I/O 完成。在任何情況下處理器通過(guò)異常表進(jìn)行一個(gè)間接過(guò)程調(diào)用到專門(mén)的異常處理程序來(lái)處理。異?？梢苑殖伤念悾?strong>中斷（interrupt)， 陷阱（trap），故障（fault）和終止（abort）。中斷是異步發(fā)生的，是來(lái)自處理器外部 I/O （鼠標(biāo)，鍵盤(pán)，網(wǎng)卡等）設(shè)備信號(hào)的結(jié)果。硬件中斷不是由任何一條專門(mén)的指令造成，從這個(gè)意義講它是異步的。剩下的異常類型（陷阱，故障，終止）是同步發(fā)生的，是執(zhí)行當(dāng)前指令的結(jié)果。我們把這種指令稱為故障指令。陷阱是有意的異常，是程序員“主動(dòng)”觸發(fā)的，就像是自己在代碼埋下一個(gè)陷阱一樣。陷阱最常見(jiàn)的用戶是進(jìn)程發(fā)起系統(tǒng)調(diào)用，通過(guò) INT 從用戶態(tài) trap 進(jìn)內(nèi)核態(tài)。故障由錯(cuò)誤情況引起，能夠被故障處理程序修正。當(dāng)故障發(fā)生時(shí)，處理器講控制轉(zhuǎn)移給故障處理程序。例如當(dāng)缺頁(yè)異常發(fā)生時(shí)，故障處理程序可以從磁盤(pán)中間對(duì)應(yīng)的頁(yè) 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í)，會(huì)引發(fā)軟件中斷。這就是上文提到的陷阱。不同于我們?cè)?Visual Studio 和 GDB 中交互式的斷點(diǎn)，如果程序在 trap 發(fā)生時(shí)，自動(dòng)執(zhí)行預(yù)定義和 handle 記錄和統(tǒng)計(jì)運(yùn)行情況，不影響程序的正常運(yùn)行，達(dá)到觀察 MySQL 的目的。為了捕捉程序運(yùn)行情況，我們?cè)诔绦蛑性O(shè)置一些 “ 陷阱 ”，并設(shè)置處理程序，我們稱之為探針。有的探針是在代碼中預(yù)定義的，有的是在運(yùn)行時(shí)動(dòng)態(tài)添加的。靜態(tài)探針是事先在程序中定義好，并編譯到程序或者內(nèi)核的探針。靜態(tài)探針只有被開(kāi)啟時(shí)才會(huì)運(yùn)行，不開(kāi)啟就不會(huì)運(yùn)行，常見(jiàn)的靜態(tài)探針包括內(nèi)核中的跟蹤點(diǎn)（tracepoints）和 USDT（Userland Statically Defined Tracing）探針。tracepoints 在代碼中埋下鉤子，在運(yùn)行時(shí)調(diào)用相連接的探針。它有“打開(kāi)”（已連接探針）和“關(guān)閉”（未連接探針）兩種狀態(tài)。當(dāng)跟蹤點(diǎn)處于“關(guān)閉”狀態(tài)時(shí)，它沒(méi)有任何作用，只增加微小的時(shí)間損失（檢查分支的條件）和空間損失。當(dāng)跟蹤點(diǎn)為“ 打開(kāi)”時(shí)，每次在調(diào)用者的執(zhí)行上下文中執(zhí)行跟蹤點(diǎn)時(shí)，都會(huì)調(diào)用相連接的探針。探針函數(shù)執(zhí)行完后，將返回到調(diào)用方。USDT和tracepoint類似，只不過(guò)是用戶態(tài)的，在代碼中插入DTRACE_PROBE()即可。動(dòng)態(tài)探針是應(yīng)用程序沒(méi)有定義，在程序運(yùn)行時(shí)動(dòng)態(tài)添加的探針。動(dòng)態(tài)探針類似于異常處理機(jī)制，當(dāng)系統(tǒng)產(chǎn)生一個(gè)異常，就會(huì)跳轉(zhuǎn)去執(zhí)行對(duì)應(yīng)的 handle。動(dòng)態(tài)探針會(huì)在函數(shù)入口和出口插入一些斷點(diǎn)，程序執(zhí)行到斷點(diǎn)時(shí)候會(huì)去執(zhí)行對(duì)應(yīng)的 handle，從而達(dá)到觀測(cè)應(yīng)用程序的目的。這里的中斷是指 trap（陷阱)，在X86體系是int3指令。
KProbes 是 Linux 內(nèi)核探針，可以用于監(jiān)視生產(chǎn)系統(tǒng)中的事件。您可以使用它來(lái)解決性能瓶頸，記錄特定事件，跟蹤問(wèn)題等。KProbes 能實(shí)時(shí)在內(nèi)核代碼中插入中斷指令，雖然這聽(tīng)上去有點(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)被探測(cè)的指令要被執(zhí)行時(shí)，先執(zhí)行pre-handler程序。同樣，當(dāng)被探測(cè)指令執(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) 最早開(kāi)發(fā)在 BSD 操作系統(tǒng)中，是 TCP/IP 包過(guò)濾的工業(yè)標(biāo)注，被 tcpdump 使用。它的工作方法有點(diǎn)特別：用戶自定義包過(guò)濾表達(dá)式，然后注入內(nèi)核中的 BPF 中運(yùn)行，這樣的好處就是在內(nèi)核進(jìn)行過(guò)濾而不是將包拷貝到用戶態(tài)，避免大量數(shù)據(jù)從內(nèi)核態(tài)拷貝到用戶態(tài)，因此具有較好的性能。后來(lái)出現(xiàn)了eBPF(extend BPF), eBPF 有自己的語(yǔ)言，用戶自己編寫(xiě)程序編譯后通過(guò) BPF 調(diào)用注入到內(nèi)核的 BPF 虛擬機(jī)中運(yùn)行，可以安全訪問(wèn)內(nèi)核內(nèi)存，它使得內(nèi)核變成可編程。運(yùn)行在內(nèi)核中因?yàn)椴恍枰褦?shù)據(jù)拷貝到用戶空間往往具有比較高的性能，因此 BPF 被很多性能追蹤工具使用。
上文介紹了相關(guān)的技術(shù)背景，接下來(lái)介紹使用追蹤工具觀測(cè) bpftrace, 它是一種使用 BPF 進(jìn)行性能分析的前端工具，使用起來(lái)很方便，類似與 awk 語(yǔ)言。由于 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è)腳本剛開(kāi)始運(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í)間，減去開(kāi)始時(shí)間（從 BPF 的 map 中獲?。褪沁@個(gè)查詢的花費(fèi)時(shí)間，如果超過(guò)閾值就打印出來(lái)。如果你會(huì)說(shuō) MySQL 有慢查詢?nèi)罩景?，不過(guò)這里優(yōu)勢(shì)是不需要重啟 MySQL，可以實(shí)時(shí)修改閾值。而且 usdt 在高級(jí)版本MySQL 會(huì)被移除，同時(shí)需要編譯時(shí)設(shè)置參數(shù) -DENABLE_DTRACE=1 才能支持 usdt。二、使用 uprobes 觀測(cè) MySQL不同與 usdt 需要事先在代碼中設(shè)置觀測(cè)點(diǎn)，uprobes 可以在程序中動(dòng)態(tài)添加，可以插入到任意函數(shù)的進(jìn)口和出口位置。下面展示是使用 uprobes 探針對(duì) dispatch_command 進(jìn)行追蹤，打印出慢查詢語(yǔ)句。
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í)記錄下來(lái)，最后打印出耗時(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 兩種探針，展示例子比較簡(jiǎn)單，還可以同時(shí)插入多個(gè)探針，使用 BPF 的 map 來(lái)共享信息，達(dá)到更強(qiáng)的觀測(cè)能力。除了這兩種探針，還可以使用 tracepoints 和 KProbe 來(lái)分析內(nèi)核態(tài)，例如網(wǎng)絡(luò)運(yùn)行情況，磁盤(pán) I/O 情況，當(dāng)然這需要你對(duì)程序有一定熟悉，要不然不知道這些探針加到哪個(gè)地方好。
數(shù)據(jù)孤島怎么破？Tendis作為騰訊自主設(shè)計(jì)和研發(fā)的分布式高性能KV存儲(chǔ)數(shù)據(jù)庫(kù)，不僅擁有大容量、低成本、強(qiáng)持久化的數(shù)據(jù)庫(kù)能力，適用于兼容Redis協(xié)議、需要大容量且較高訪問(wèn)性能的溫冷數(shù)據(jù)存儲(chǔ)場(chǎng)景。同時(shí)還支持tendis到tendis/redis的數(shù)據(jù)遷移能力，通過(guò)Tendis遷移工具，可輕松實(shí)現(xiàn)數(shù)據(jù)的流動(dòng)。4月28日（下周三）晚19：30，將由負(fù)責(zé)Tendis遷移工具開(kāi)發(fā)的騰訊云數(shù)據(jù)庫(kù)高級(jí)工程師，為大家揭秘Tendis遷移工具的設(shè)計(jì)與實(shí)現(xiàn)。掃描下方二維碼或點(diǎn)擊「閱讀原文」，即可進(jìn)行報(bào)名！
