這是我調(diào)過的最難調(diào)的Bug
你調(diào)過的最難調(diào)的bug是哪個(gè)？
每個(gè)程序員都有些不畏死亡決戰(zhàn)猛獸的英雄事跡。以下這些是我的。
內(nèi)存沖突
畢業(yè)不到半年，拿著剛到手的文憑，我在Lexmark公司的一個(gè)嵌入式Linux固件開發(fā)團(tuán)隊(duì)中負(fù)責(zé)追蹤一個(gè)內(nèi)存沖突的問題。因?yàn)閮?nèi)存沖突的原因和問題表象總是相差非常大，所以這類問題很難調(diào)。有可能是因?yàn)榫彺嬉绯?，也有可能是指針未初始化，或是指針被多次free，亦或是某處的DMA錯(cuò)誤，但是你所見的卻是一堆神秘的問題：掛起、指令未定義、打印錯(cuò)誤，以及未處理的內(nèi)核錯(cuò)誤。這些都非常頻繁，內(nèi)存沖突看上去似乎是隨機(jī)出現(xiàn)又很難重現(xiàn)。
要調(diào)試這種問題，第一步是可重現(xiàn)問題。在我們奇跡般地找到這樣一個(gè)場景之后，故事開始變得好玩起來。
當(dāng)時(shí)，我們發(fā)現(xiàn)在運(yùn)行時(shí)因內(nèi)存沖突而產(chǎn)生的程序崩潰每幾百小時(shí)就會(huì)出現(xiàn)一次。之后有一天有人發(fā)現(xiàn)一個(gè)特別的打印任務(wù)會(huì)產(chǎn)生內(nèi)存沖突從而在幾分鐘之內(nèi)就使程序崩潰。我從來不知道為什么這個(gè)打印任務(wù)會(huì)產(chǎn)生這個(gè)問題?，F(xiàn)在，我們就可以進(jìn)一步做些什么了。
調(diào)試
這個(gè)問題可重現(xiàn)之后，我就開始尋找崩潰中出現(xiàn)的模式。最引人注意的是未定義指令和內(nèi)核錯(cuò)誤，它們差不多三分之一的時(shí)間就會(huì)發(fā)生一次。未定義指令的地址是一個(gè)合理的內(nèi)核代碼地址，但是CPU讀到的這個(gè)指令卻不是我們期望出現(xiàn)的。這就很簡單了，可能是有人不小心寫了這些指令。把這些未定義指令的句柄打印出來之后，我可以看到這些錯(cuò)誤的指令所在位置的周邊內(nèi)存的狀態(tài)。
在做了大量失敗的將更多的代碼排除出崩潰的嘗試之后，一個(gè)特殊的崩潰漸漸顯現(xiàn)。
崩潰之王
這個(gè)崩潰解開了所有秘密。當(dāng)時(shí)我們用了一個(gè)雙核CPU。在這個(gè)特殊的崩潰里，首先CPU1在有效的模塊地址范圍內(nèi)收到了一個(gè)未處理的內(nèi)核錯(cuò)誤，而此時(shí)它正在嘗試執(zhí)行模塊代碼，這段代碼可能是一個(gè)沖突的頁表或是一個(gè)無效TLB。而正在處理這個(gè)錯(cuò)誤時(shí)，CPU0在內(nèi)核地址空間內(nèi)收到了一個(gè)非法的指令陷阱。
以下是從修改后的未定義指令句柄中打印出來的數(shù)據(jù)（已轉(zhuǎn)為物理地址，括號(hào)中是出錯(cuò)地址）
- undefined instruction: pc=0018abc4
- 0018aba0: e7d031a2 e1b03003 1a00000e e2822008
- 0018abb0: e1520001 3afffff9 e1a00001 e1a0f00e
- 0018abc0: 0bd841e6 (ceb3401c) 00000004 00000001
- 0018abd0: 0d066010 5439541b 49fa30e7 c0049ab8
- 0018abe0: e2822001 eafffff1 e2630000 e0033000
- 0018abf0: e16f3f13 e263301f e0820003 e1510000
以下是內(nèi)存域應(yīng)該顯示的數(shù)據(jù)：
- 0018aba0: e7d031a2 e1b03003 1a00000e e2822008
- 0018abb0: e1520001 3afffff9 e1a00001 e1a0f00e
- 0018abc0: e3310000 (0afffffb) e212c007 0afffff3
- 0018abd0: e7d031a2 e1b03c33 1a000002 e3822007
- 0018abe0: e2822001 eafffff1 e2630000 e0033000
- 0018abf0: e16f3f13 e263301f e0820003 e1510000
確切地來說，只有一行緩存(中間那32byte)是有沖突的。一個(gè)同事指出沖突行中0x49fa30e7這個(gè)字是一個(gè)魔術(shù)cookie，它標(biāo)記了系統(tǒng)中一個(gè)特殊環(huán)形緩沖區(qū)的入口。入口值的最后一個(gè)字永遠(yuǎn)是一個(gè)時(shí)間戳，所以0x5439541b是上一個(gè)入口的時(shí)間戳。我決定去讀取這個(gè)環(huán)形緩沖的內(nèi)容，但它現(xiàn)在掛在一個(gè)不可執(zhí)行的KGDB提示那了。機(jī)器現(xiàn)在跟死了一樣。
冷啟動(dòng)攻擊
為獲取環(huán)形緩沖區(qū)的數(shù)據(jù)，我進(jìn)行了一次冷啟動(dòng)攻擊。我為正在使用的主板搞到了一份概要拷貝，然后發(fā)現(xiàn)CPU的復(fù)位線上連了一塊不受歡迎的板子。我把它短路了，重置CPU而不妨礙DRAM的完整性。然后，我把Boot掛載在引導(dǎo)程序上。
在引導(dǎo)程序里，我dump到了問題中環(huán)形緩沖區(qū)的內(nèi)容。謝天謝地，這個(gè)緩存總是在一個(gè)固定的物理地址上被定位到，所以找到它不是問題了。
通過分析錯(cuò)誤時(shí)間戳周邊的環(huán)形緩沖區(qū)，我們發(fā)現(xiàn)了兩個(gè)老的cache line。這兩個(gè)cache line里有有效數(shù)據(jù)，但是在這兩個(gè)cache line里的時(shí)間戳卻是環(huán)形緩沖區(qū)里之前的時(shí)間。
導(dǎo)致CPU0上未定義指令的cache line與環(huán)形緩沖區(qū)里那兩個(gè)老cache line之一相當(dāng)契合，但是這并不說明其他可能的地方也是這樣。我發(fā)現(xiàn)一個(gè)決定性的證據(jù)。假設(shè)，另一個(gè)消失的cache line是導(dǎo)致CPU1上未處理內(nèi)核錯(cuò)誤的元兇。
錯(cuò)置的cache line
cache line應(yīng)該被寫入0x0ebd2bc0（環(huán)形緩沖區(qū)里的cache line），但是事實(shí)上卻寫入了0x0018abc0（沖突的內(nèi)核碼）。這些地址在我們CPU上屬于相同的緩存，它們的位[14:5]的值是相同的。不知為何它們有別名。
- bit 28 24 20 16 12 8 4 0
- | | | | | | | |
- 0x0ebd2bc0 in binary is 0000 1110 1011 1101 0010 1011 1100 0000
- 0x0018abc0 in binary is 0000 0000 0001 1000 1010 1011 1100 0000
一個(gè)地址的低5位是cache line(32字節(jié)cache line)里的索引。后10位，即位[14:5]，表示緩存集。剩下的17位，即位[31:15]，用來表示緩存里當(dāng)前存的是哪個(gè)cache line.
我向我們的CPU供應(yīng)商提交了一個(gè)bug報(bào)告，之后他們制定了一個(gè)解決方案，并在下一版本CPU里修復(fù)了這個(gè)bug。
我期望聽到更多牛掰的此類故事，也期望我自己可以再攢點(diǎn)這樣的。
原文鏈接： Peter Lundgren 翻譯： 伯樂在線 - Elaine
