一、發現Bug
一個程式設計師在沒有成長成為架構師之前,幾乎都要跟 Bug為伴,程式設計師有很多時間都是花在了查詢各種 Bug上。
我印象深刻的一個Bug, 是一個伺服器網路框架無鎖佇列的 Bug 。那個 Bug 連續查找了五天的時間,才最後定位出來。
當時我們的分散式儲存系統出現了效能瓶頸,定位後發現瓶頸是在伺服器網路框架上,所以我們決定為此替換一個最新研發的網路框架。這個新的網路框架為了追求高的效能,採用了無鎖佇列的設計。
第一天編碼測試完成後。測試環境跑,完全正常,特地搞了一堆 log 來重放請求,程式跑得特別歡快。解決了當時的效能瓶頸,感覺特別的開心,但好景不長,服務部署到現網環境,跑不到一個小時,就 coredump 了。
嘗試上線了幾次,每次都是跑半個多小時,就 coredump 。
當時的第一反應是新網路框架的問題,這是很直覺的反應,但很快就產生了懷疑,因為這個框架也有其它模組在用,也沒產生問題,當時覺得詭異了。
仔細查看了程式碼的修改記錄,特定檢查了版本管理系統的 log, 做了程式碼 diff, 確定確實只有這部分的修改。憑著經驗,我說服自己,這個時候應該堅信最明確的邏輯,不要走到其他歪路上去。
第二天,我把這個框架單獨拎了出來,特地寫了一個測試的模組,並用測試程式碼生成了一堆的請求資料,傳送給測試模組。它瘋狂的運轉起來,跑了一個多小時,跑得很歡快,一切正常,啥 Bug 都沒有。
開大了併發,繼續壓,依然沒有問題。懵逼了!不知咋回事。再次小心得灰度系統上線,跑不到一個小時還是 coredump 了, 這個時候,我開始懷疑人生了,這個是咋回事了,都想砸鍵盤了都。
然後我冷靜了下來,經驗告訴我,這時應該按照正常流程完整地跑一遍測試模組。於是我把那個測試模組打包成了現網模組,切走了一臺現網機器的流量,把測試模組給上線到了一臺現網機器。
之後用工具往現網機器傳送資料,不到一個小時,coredump 了。終於復現了這個 cordedump, 那一刻猶如哥倫布發現了新大陸,簡直欣喜若狂啊。這個時候已經是第三天了。
我復現了 Bug,但依然沒辦法定位出具體的原因。coredump 出來的棧是全亂的,沒有任何價值,接下來,就開始用 log 跟蹤法了。
我依據資料的流轉過程,在每個關鍵點,都打上 log,log 包含了所在的函式,行數,程式邏輯的編號,全部的關鍵資料等等。我仔細地設計了這個log,爭取打得不多不少,太多容易看暈頭,而且太多無效的資訊,會掩蓋了真正的問題;太少,資訊不足,又不足以判斷,所以這種情況下打 log 也是個藝術活。
透過精心設計的 log, 終於發現數據在一個特定的環節混亂後,程式就一定會 coredump。分析log , 發現數據包在最後時刻是完整的,但包似乎出現了亂序和重複。這個時候,才開始意識到可能是無鎖佇列的問題,因為只有隊列出問題,包的進出順序才會亂掉。
然後又花了半天的時間,專門為無鎖佇列寫了測試用例,用資料瘋狂地懟。在測試環境,依然一切安好,但上線到正式環境,壓測半小後,終於掛了。終於看到了勝利的曙光!這個時候已經是第四天了!
到現在已經很明確是無鎖佇列的問題了。但這個資料結構的程式碼不到 200行。我拉了兩個同事一起 review,都沒發現問題。但就是 coredump 了。
奇葩了,又陷入了人生懷疑,開始懷疑記憶體,懷疑 cpu,結果換了機器,還是一樣。
後來,仔細地對比了現網環境和測試環境的區別,機器型別,作業系統版本都一樣。然後編譯器?咦!編譯器?上去看了一下,結果發現編譯器的版本不一樣!這段時間我所使用的現網編譯環境升級了新的 gcc 版本,但測試編譯環境,還是舊的版本的。(這個也比較坑)
當時的直覺是肯定跟編譯器相關,但程式碼都一樣,難道是編譯器bug?不可能吧 ?! 後來想,不如將它們轉換成彙編看看吧。於是用兩個版本的編譯器將C的程式碼各自轉換成了彙編。然後diff 彙編程式碼,哇!發現真的有一行是不同的!
後來自己分析對比,發現是因為我們開啟了gcc最高級別的程式碼效能最佳化,不同版本的 gcc 在一些沒有特定依賴的語句上的最佳化是不同的。
說人話,就是有一段程式碼,如果加了鎖,兩個版本的編譯器下,都會產生一樣的彙編,如果沒有加鎖,程式碼有一行的順序被調整了,當然,從編譯器最佳化的角度講是對的,是我們使用姿勢不對。
但無論怎麼樣,終於找出了這個問題。蒼天啊! 找了五天呀! 最後當然是開開心心地上線了。
查這個bug 確實花費了很多的時間,不過也是沒辦法,你不解決bug,就不能上線,但中間也收穫不少,特別是對編譯器最佳化有了很深的印象,也算是為自己的查 Bug 能力,又貢獻了一波經驗吧。
對於 Bug , 我分享下自己的一些認識和建議。
二、面對 Bug 的態度
只要你持續地寫程式碼,就一定會持續的產生 Bug,所以第一個事情是要擺正對 Bug 的心態。我遇到過兩個極端。
第一個極端。
遇到過一個leader,對系統質量相當重視,對我們寫的程式碼要求很高,每次設計並寫完一個新的系統,他喜歡跟你算這次的系統上線,產生了多少次故障,這半年時間產生了多少個 Bug,每個 Bug 的影響範圍如何。
我們一堆人被搞得特別累,戰戰兢兢,到後面,大家都比較排斥去做最佳化,去重構程式碼,只求無過,不求有功了。所以,我覺得這種方式不好,對 Bug 帶著一種比較包容的態度去看待,可以減少不少的心理負擔。
第二個極端。
後來去了一個新的團隊。新的團隊很重視業務和工程迭代的速度,所以對程式碼質量和 Bug 的容忍度很高。如果是一個新上線的業務,是默許 Bug 存在的。
這種對質量過於鬆散的要求,在後面也帶來不好的影響。大家對 Bug 太免疫了,以至於出現 Bug 和 故障的時候,大家都不夠緊張。系統質量有一段時間出現比較大的問題,還因此被部門經理特訓了一番,後面透過各種措施,才慢慢提高了整體的系統質量。
上面兩種極端都不可取,應該很重視 Bug,儘量避免 Bug,但也不應該唯 Bug 多少論業績。
具體到 Bug 的查詢上,我說說我的一些經驗。
三、Bug 的復現
我把 Bug 分為可重現的 Bug 和不可復現的 Bug 。
對於可重現的 Bug , 查詢起來比較容易,比如可以用”二分查詢“的方式,從模組層面開始定位起,每次折半,每次折半地縮小範圍,一直到程式碼層面。
在程式碼層面,遵循一些常用的原則:比如看到記憶體複製,直覺上要想到記憶體越界;看到陣列,就要考慮是否索引越界;看到指標,就要考慮是否正確解構;看到多執行緒,就要考慮是否執行緒安全;
對於不可重現的 Bug , 第一步就是要把它重現出來。有時候特別的難,特別是併發形態下產生的 Bug ,出現的時機和觸發條件都不清楚。對於這種 Bug ,只能透過各種嘗試去復現它。
比如將多併發調整為單併發的方式,看能否復現,如果可以復現,就可以轉化為可復現的 Bug ,用”二分查詢“的方式去排查。
如果不能復現,那極大機率是併發問題。這個時候最好先停止排查,仔細分析程式在併發狀態下可能出問題的點。大部分併發問題的根源,是互斥資料沒有被正確讀寫,或者一些共享狀態被錯誤修改。
四、靜態程式碼檢查
利用coverity等程式碼檢查工具進行程式碼的靜態檢查可以發現很多潛在的問題,而且修復的成本很低。團隊後來引入了這個檢查工具,確實帶來了不錯的效果。類似變數未初始化,疑似的記憶體越界等都有可能被檢查出來。
編譯器的 warning。有些同學一開始的時候對 warning 不重視。我們團隊早期也遇到過這個情況。
那時候產品迭代的速度很快,所以大家寫完程式碼,能夠編譯透過,就進行各種測試,然後準備上線了。一開始的一兩個warning, 不太理會。後面發現越積越多,到最後終於成為一個不得不解決的問題。
部門還為此特地立項,來消除warning。先是在內部多次強調了這個理念,然後從基礎庫,基礎模組開始實施,基礎程式碼部分統一 fix warning, 然後開啟編譯器把 warning 當 error 的開關。完成之後,再逐步地推業務模組進行修改。反正折騰了好一段時間。
五、工欲善其事必先利其器
程式碼 Bug 出現的時候,善用一些排查工具可以極大得提升效率。比如對於C/C++ 的 gdb 除錯,記憶體洩漏時候 valgrind 的檢測,linux 下面用 perf top 來析 cpu 的消耗等。
一開始的時候,我對這些工具不重視,老是覺得真正使用的時候,去查文件就行。後面才發現,用工具查著問題時候,遇到不會用的命令或功能,再去查文件,是個痛苦的事情,來回切換的開銷也使得效率低下。
後面就對這些輔助工具的使用重視了起來,專門花時間去學習和練習使用,反而提升了不少的效率
六、打 log 的藝術
很多時候,出現一個 Bug,未能定位出來,需要打上更多額外的 log 來輔助排查。一開始的時候,是想到一點,打一個 log,後面發現這麼做沒有章法,邏輯不清晰, 排查效率低下。
後來學會了,遇到 Bug 後,先在腦子裡面分析一番,然後花一兩個小時詳細地設計 log 的格式和打 log 的位置。發現這種方式對查問題的效率提升很大。
所以遇到 Bug 的時候不要急躁,先靜下來心來分析,在腦海裡盡力重現出完整的執行邏輯,然後仔細地進行 log 設計,包括 log 包含的欄位,打 log 的點等。這樣能極大的提升排查問題的效率。
七、結語
作者丨大飛碼字