這是我調過的最難調的Bug
你調過的最難調的bug是哪個？
每個程序員都有些不畏死亡決戰猛獸的英雄事跡。以下這些是我的。
內存沖突
畢業不到半年，拿著剛到手的文憑，我在Lexmark公司的一個嵌入式Linux固件開發團隊中負責追蹤一個內存沖突的問題。因為內存沖突的原因和問題表象總是相差非常大，所以這類問題很難調。有可能是因為緩存溢出，也有可能是指針未初始化，或是指針被多次free，亦或是某處的DMA錯誤，但是你所見的卻是一堆神秘的問題：掛起、指令未定義、打印錯誤，以及未處理的內核錯誤。這些都非常頻繁，內存沖突看上去似乎是隨機出現又很難重現。
要調試這種問題，第一步是可重現問題。在我們奇跡般地找到這樣一個場景之后，故事開始變得好玩起來。
當時，我們發現在運行時因內存沖突而產生的程序崩潰每幾百小時就會出現一次。之后有一天有人發現一個特別的打印任務會產生內存沖突從而在幾分鐘之內就使程序崩潰。我從來不知道為什么這個打印任務會產生這個問題。現在，我們就可以進一步做些什么了。
調試
這個問題可重現之后，我就開始尋找崩潰中出現的模式。最引人注意的是未定義指令和內核錯誤，它們差不多三分之一的時間就會發生一次。未定義指令的地址是一個合理的內核代碼地址，但是CPU讀到的這個指令卻不是我們期望出現的。這就很簡單了，可能是有人不小心寫了這些指令。把這些未定義指令的句柄打印出來之后，我可以看到這些錯誤的指令所在位置的周邊內存的狀態。
在做了大量失敗的將更多的代碼排除出崩潰的嘗試之后，一個特殊的崩潰漸漸顯現。
崩潰之王
這個崩潰解開了所有秘密。當時我們用了一個雙核CPU。在這個特殊的崩潰里，首先CPU1在有效的模塊地址范圍內收到了一個未處理的內核錯誤，而此時它正在嘗試執行模塊代碼，這段代碼可能是一個沖突的頁表或是一個無效TLB。而正在處理這個錯誤時，CPU0在內核地址空間內收到了一個非法的指令陷阱。
以下是從修改后的未定義指令句柄中打印出來的數據（已轉為物理地址，括號中是出錯地址）
- 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
以下是內存域應該顯示的數據：
- 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)是有沖突的。一個同事指出沖突行中0x49fa30e7這個字是一個魔術cookie，它標記了系統中一個特殊環形緩沖區的入口。入口值的最后一個字永遠是一個時間戳，所以0x5439541b是上一個入口的時間戳。我決定去讀取這個環形緩沖的內容，但它現在掛在一個不可執行的KGDB提示那了。機器現在跟死了一樣。
冷啟動攻擊
為獲取環形緩沖區的數據，我進行了一次冷啟動攻擊。我為正在使用的主板搞到了一份概要拷貝，然后發現CPU的復位線上連了一塊不受歡迎的板子。我把它短路了，重置CPU而不妨礙DRAM的完整性。然后，我把Boot掛載在引導程序上。
在引導程序里，我dump到了問題中環形緩沖區的內容。謝天謝地，這個緩存總是在一個固定的物理地址上被定位到，所以找到它不是問題了。
通過分析錯誤時間戳周邊的環形緩沖區，我們發現了兩個老的cache line。這兩個cache line里有有效數據，但是在這兩個cache line里的時間戳卻是環形緩沖區里之前的時間。
導致CPU0上未定義指令的cache line與環形緩沖區里那兩個老cache line之一相當契合，但是這并不說明其他可能的地方也是這樣。我發現一個決定性的證據。假設，另一個消失的cache line是導致CPU1上未處理內核錯誤的元兇。
錯置的cache line
cache line應該被寫入0x0ebd2bc0（環形緩沖區里的cache line），但是事實上卻寫入了0x0018abc0（沖突的內核碼）。這些地址在我們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
一個地址的低5位是cache line(32字節cache line)里的索引。后10位，即位[14:5]，表示緩存集。剩下的17位，即位[31:15]，用來表示緩存里當前存的是哪個cache line.
我向我們的CPU供應商提交了一個bug報告，之后他們制定了一個解決方案，并在下一版本CPU里修復了這個bug。
我期望聽到更多牛掰的此類故事，也期望我自己可以再攢點這樣的。
原文鏈接： Peter Lundgren 翻譯： 伯樂在線 - Elaine
