懵逼了!一個(gè)歷時(shí)五天的Bug......
一個(gè)程序員在沒有成長(zhǎng)為架構(gòu)師之前,幾乎都要跟 Bug 為伴,程序員有很多時(shí)間都是花在了查找各種 Bug 上。
我印象深刻的一個(gè) Bug,是一個(gè)服務(wù)器網(wǎng)絡(luò)框架無鎖隊(duì)列的 Bug 。那個(gè) Bug 連續(xù)查找了五天的時(shí)間,才***定位出來。
當(dāng)時(shí)我們的分布式存儲(chǔ)系統(tǒng)出現(xiàn)了性能瓶頸,定位后發(fā)現(xiàn)瓶頸是在服務(wù)器網(wǎng)絡(luò)框架上,所以我們決定為此替換一個(gè)***研發(fā)的網(wǎng)絡(luò)框架。這個(gè)新的網(wǎng)絡(luò)框架為了追求高的性能,采用了無鎖隊(duì)列的設(shè)計(jì)。
***天編碼測(cè)試完成后,在測(cè)試環(huán)境跑,完全正常,特地搞了一堆 Log 來重放請(qǐng)求,程序跑得特別歡快。
解決了當(dāng)時(shí)的性能瓶頸,感覺特別的開心,但好景不長(zhǎng),服務(wù)部署到現(xiàn)網(wǎng)環(huán)境,跑不到一個(gè)小時(shí),就 Core Dump 了。
嘗試上線了幾次,每次都是跑半個(gè)多小時(shí),就 Core Dump 。
當(dāng)時(shí)的***反應(yīng)是新網(wǎng)絡(luò)框架的問題,這是很直覺的反應(yīng),但很快就產(chǎn)生了懷疑,因?yàn)檫@個(gè)框架也有其它模塊在用,也沒產(chǎn)生問題,當(dāng)時(shí)覺得詭異了。
仔細(xì)查看了代碼的修改記錄,特定檢查了版本管理系統(tǒng)的 Log,做了代碼 Diff,確定確實(shí)只有這部分的修改。
憑著經(jīng)驗(yàn),我說服自己,這個(gè)時(shí)候應(yīng)該堅(jiān)信最明確的邏輯,不要走到其他歪路上去。
第二天,我把這個(gè)框架單獨(dú)拎了出來,特地寫了一個(gè)測(cè)試的模塊,并用測(cè)試代碼生成了一堆的請(qǐng)求數(shù)據(jù),發(fā)送給測(cè)試模塊。
它瘋狂的運(yùn)轉(zhuǎn)起來,跑了一個(gè)多小時(shí),跑得很歡快,一切正常,啥 Bug 都沒有。
開大了并發(fā),繼續(xù)壓,依然沒有問題。懵逼了!不知咋回事。再次小心得灰度系統(tǒng)上線,跑不到一個(gè)小時(shí)還是 Core Dump 了,這個(gè)時(shí)候,我開始懷疑人生了,這個(gè)是咋回事了,都想砸鍵盤了都。
然后我冷靜了下來,經(jīng)驗(yàn)告訴我,這時(shí)應(yīng)該按照正常流程完整地跑一遍測(cè)試模塊。
于是我把那個(gè)測(cè)試模塊打包成了現(xiàn)網(wǎng)模塊,切走了一臺(tái)現(xiàn)網(wǎng)機(jī)器的流量,把測(cè)試模塊給上線到了一臺(tái)現(xiàn)網(wǎng)機(jī)器。
之后用工具往現(xiàn)網(wǎng)機(jī)器發(fā)送數(shù)據(jù),不到一個(gè)小時(shí),Core Dump 了。終于復(fù)現(xiàn)了這個(gè) Corde Dump, 那一刻猶如哥倫布發(fā)現(xiàn)了新大陸,簡(jiǎn)直欣喜若狂啊。這個(gè)時(shí)候已經(jīng)是第三天了。
我復(fù)現(xiàn)了 Bug,但依然沒辦法定位出具體的原因。Core Dump 出來的棧是全亂的,沒有任何價(jià)值,接下來,就開始用 Log 跟蹤法了。
我依據(jù)數(shù)據(jù)的流轉(zhuǎn)過程,在每個(gè)關(guān)鍵點(diǎn),都打上 Log,Log 包含了所在的函數(shù),行數(shù),程序邏輯的編號(hào),全部的關(guān)鍵數(shù)據(jù)等等。
我仔細(xì)地設(shè)計(jì)了這個(gè) Log,爭(zhēng)取打得不多不少,太多容易看暈頭,而且太多無效的信息,會(huì)掩蓋了真正的問題;太少,信息不足,又不足以判斷,所以這種情況下打 Log 也是個(gè)藝術(shù)活。
通過精心設(shè)計(jì)的 Log,終于發(fā)現(xiàn)數(shù)據(jù)在一個(gè)特定的環(huán)節(jié)混亂后,程序就一定會(huì) Core Dump。
分析 Log , 發(fā)現(xiàn)數(shù)據(jù)包在***時(shí)刻是完整的,但包似乎出現(xiàn)了亂序和重復(fù)。這個(gè)時(shí)候,才開始意識(shí)到可能是無鎖隊(duì)列的問題,因?yàn)橹挥嘘?duì)列出問題,包的進(jìn)出順序才會(huì)亂掉。
然后又花了半天的時(shí)間,專門為無鎖隊(duì)列寫了測(cè)試用例,用數(shù)據(jù)瘋狂地懟。在測(cè)試環(huán)境,依然一切安好,但上線到正式環(huán)境,壓測(cè)半小時(shí)后,終于掛了。終于看到了勝利的曙光!這個(gè)時(shí)候已經(jīng)是第四天了!
到現(xiàn)在已經(jīng)很明確是無鎖隊(duì)列的問題了。但這個(gè)數(shù)據(jù)結(jié)構(gòu)的代碼不到 200 行。我拉了兩個(gè)同事一起 Review,都沒發(fā)現(xiàn)問題。但就是 Core Dump 了。
奇葩了,又陷入了人生懷疑,開始懷疑內(nèi)存,懷疑 CPU,結(jié)果換了機(jī)器,還是一樣。
后來,仔細(xì)地對(duì)比了現(xiàn)網(wǎng)環(huán)境和測(cè)試環(huán)境的區(qū)別,機(jī)器類型,操作系統(tǒng)版本都一樣。然后編譯器?咦!編譯器?上去看了一下,結(jié)果發(fā)現(xiàn)編譯器的版本不一樣!
這段時(shí)間我所使用的現(xiàn)網(wǎng)編譯環(huán)境升級(jí)了新的 GCC 版本,但測(cè)試編譯環(huán)境,還是舊的版本的。(這個(gè)也比較坑)
當(dāng)時(shí)的直覺是肯定跟編譯器相關(guān),但代碼都一樣,難道是編譯器 Bug?不可能吧 ?!
后來想,不如將它們轉(zhuǎn)換成匯編看看吧。于是用兩個(gè)版本的編譯器將 C 的代碼各自轉(zhuǎn)換成了匯編。然后 Diff 匯編代碼,哇!發(fā)現(xiàn)真的有一行是不同的!
后來自己分析對(duì)比,發(fā)現(xiàn)是因?yàn)槲覀冮_啟了 GCC ***級(jí)別的代碼性能優(yōu)化,不同版本的 GCC 在一些沒有特定依賴的語句上的優(yōu)化是不同的。
說人話,就是有一段代碼,如果加了鎖,兩個(gè)版本的編譯器下,都會(huì)產(chǎn)生一樣的匯編,如果沒有加鎖,代碼有一行的順序被調(diào)整了,當(dāng)然,從編譯器優(yōu)化的角度講是對(duì)的,是我們使用姿勢(shì)不對(duì)。
但無論怎么樣,終于找出了這個(gè)問題。蒼天啊! 找了五天呀!***當(dāng)然是開開心心地上線了。
查這個(gè) Bug 確實(shí)花費(fèi)了很多的時(shí)間,不過也是沒辦法,你不解決 Bug,就不能上線,但中間也收獲不少,特別是對(duì)編譯器優(yōu)化有了很深的印象,也算是為自己的查 Bug 能力,又貢獻(xiàn)了一波經(jīng)驗(yàn)吧。
對(duì)于 Bug , 我分享下自己的一些認(rèn)識(shí)和建議。
面對(duì) Bug 的態(tài)度
只要你持續(xù)地寫代碼,就一定會(huì)持續(xù)的產(chǎn)生 Bug,所以***個(gè)事情是要擺正對(duì) Bug 的心態(tài)。我遇到過兩個(gè)極端。
***個(gè)極端
遇到過一個(gè) Leader,對(duì)系統(tǒng)質(zhì)量相當(dāng)重視,對(duì)我們寫的代碼要求很高,每次設(shè)計(jì)并寫完一個(gè)新的系統(tǒng),他喜歡跟你算這次的系統(tǒng)上線,產(chǎn)生了多少次故障,這半年時(shí)間產(chǎn)生了多少個(gè) Bug,每個(gè) Bug 的影響范圍如何。
我們一堆人被搞得特別累,戰(zhàn)戰(zhàn)兢兢,到后面,大家都比較排斥去做優(yōu)化,去重構(gòu)代碼,只求無過,不求有功了。
所以,我覺得這種方式不好,對(duì) Bug 帶著一種比較包容的態(tài)度去看待,可以減少不少的心理負(fù)擔(dān)。
第二個(gè)極端
后來去了一個(gè)新的團(tuán)隊(duì)。新的團(tuán)隊(duì)很重視業(yè)務(wù)和工程迭代的速度,所以對(duì)代碼質(zhì)量和 Bug 的容忍度很高。如果是一個(gè)新上線的業(yè)務(wù),是默許 Bug 存在的。
這種對(duì)質(zhì)量過于松散的要求,在后面也帶來不好的影響。大家對(duì) Bug 太免疫了,以至于出現(xiàn) Bug 和故障的時(shí)候,大家都不夠緊張。
系統(tǒng)質(zhì)量有一段時(shí)間出現(xiàn)比較大的問題,還因此被部門經(jīng)理特訓(xùn)了一番,后面通過各種措施,才慢慢提高了整體的系統(tǒng)質(zhì)量。
上面兩種極端都不可取,應(yīng)該很重視 Bug,盡量避免 Bug,但也不應(yīng)該唯 Bug 多少論業(yè)績(jī)。
具體到 Bug 的查找上,我說說我的一些經(jīng)驗(yàn)。
Bug 的復(fù)現(xiàn)
我把 Bug 分為可重現(xiàn)的 Bug 和不可復(fù)現(xiàn)的 Bug 。
對(duì)于可重現(xiàn)的 Bug , 查找起來比較容易,比如可以用”二分查找“的方式,從模塊層面開始定位起,每次折半,每次折半地縮小范圍,一直到代碼層面。
在代碼層面,遵循一些常用的原則,比如:
- 看到內(nèi)存拷貝,直覺上要想到內(nèi)存越界。
- 看到數(shù)組,就要考慮是否索引越界。
- 看到指針,就要考慮是否正確解構(gòu)。
- 看到多線程,就要考慮是否線程安全。
- 對(duì)于不可重現(xiàn)的 Bug,***步就是要把它重現(xiàn)出來。
有時(shí)候特別的難,特別是并發(fā)形態(tài)下產(chǎn)生的 Bug,出現(xiàn)的時(shí)機(jī)和觸發(fā)條件都不清楚。對(duì)于這種 Bug,只能通過各種嘗試去復(fù)現(xiàn)它。
比如將多并發(fā)調(diào)整為單并發(fā)的方式,看能否復(fù)現(xiàn),如果可以復(fù)現(xiàn),就可以轉(zhuǎn)化為可復(fù)現(xiàn)的 Bug,用”二分查找“的方式去排查。
如果不能復(fù)現(xiàn),那極大概率是并發(fā)問題。這個(gè)時(shí)候***先停止排查,仔細(xì)分析程序在并發(fā)狀態(tài)下可能出問題的點(diǎn)。
大部分并發(fā)問題的根源,是互斥數(shù)據(jù)沒有被正確讀寫,或者一些共享狀態(tài)被錯(cuò)誤修改。
靜態(tài)代碼檢查
利用 Coverity 等代碼檢查工具進(jìn)行代碼的靜態(tài)檢查可以發(fā)現(xiàn)很多潛在的問題,而且修復(fù)的成本很低。團(tuán)隊(duì)后來引入了這個(gè)檢查工具,確實(shí)帶來了不錯(cuò)的效果。類似變量未初始化,疑似的內(nèi)存越界等都有可能被檢查出來。
編譯器的 Warning。有些同學(xué)一開始的時(shí)候?qū)?Warning 不重視。我們團(tuán)隊(duì)早期也遇到過這個(gè)情況。
那時(shí)候產(chǎn)品迭代的速度很快,所以大家寫完代碼,能夠編譯通過,就進(jìn)行各種測(cè)試,然后準(zhǔn)備上線了。
一開始的一兩個(gè) Warning,不太理會(huì)。后面發(fā)現(xiàn)越積越多,到***終于成為一個(gè)不得不解決的問題。
部門還為此特地立項(xiàng),來消除 Warning。先是在內(nèi)部多次強(qiáng)調(diào)了這個(gè)理念,然后從基礎(chǔ)庫,基礎(chǔ)模塊開始實(shí)施,基礎(chǔ)代碼部分統(tǒng)一 Fix Warning,然后開啟編譯器把 Warning 當(dāng) Error 的開關(guān)。
完成之后,再逐步地推業(yè)務(wù)模塊進(jìn)行修改。反正折騰了好一段時(shí)間。
工欲善其事必先利其器
代碼 Bug 出現(xiàn)的時(shí)候,善用一些排查工具可以極大得提升效率。比如對(duì)于 C/C++ 的 GDB 調(diào)試,內(nèi)存泄漏時(shí)候 Valgrind 的檢測(cè),Linux 下面用 Perf Top 來析 CPU 的消耗等。
一開始的時(shí)候,我對(duì)這些工具不重視,老是覺得真正使用的時(shí)候,去查文檔就行。
后面才發(fā)現(xiàn),用工具查著問題時(shí)候,遇到不會(huì)用的命令或功能,再去查文檔,是個(gè)痛苦的事情,來回切換的開銷也使得效率低下。
后面就對(duì)這些輔助工具的使用重視了起來,專門花時(shí)間去學(xué)習(xí)和練習(xí)使用,反而提升了不少的效率。
打 Log 的藝術(shù)
很多時(shí)候,出現(xiàn)一個(gè) Bug,未能定位出來,需要打上更多額外的 Log 來輔助排查。一開始的時(shí)候,是想到一點(diǎn),打一個(gè) Log,后面發(fā)現(xiàn)這么做沒有章法,邏輯不清晰, 排查效率低下。
后來學(xué)會(huì)了,遇到 Bug 后,先在腦子里面分析一番,然后花一兩個(gè)小時(shí)詳細(xì)地設(shè)計(jì) Log 的格式和打 Log 的位置。發(fā)現(xiàn)這種方式對(duì)查問題的效率提升很大。
所以遇到 Bug 的時(shí)候不要急躁,先靜下來心來分析,在腦海里盡力重現(xiàn)出完整的運(yùn)行邏輯,然后仔細(xì)地進(jìn)行 Log 設(shè)計(jì),包括 Log 包含的字段,打 Log 的點(diǎn)等。這樣能極大的提升排查問題的效率。
結(jié)語
Bug 是程序員最不愿意面對(duì),但又經(jīng)常出現(xiàn)的一個(gè) “詭異生物“。對(duì)待 Bug 要有正確的心態(tài),***不要跟業(yè)績(jī)強(qiáng)綁定,也不能太過于疏忽。
Bug 的排查是個(gè)很復(fù)雜的事情,每個(gè)人都有自己的方式和做法,如果你有好的做法和建議,也歡迎在留言區(qū)分享給大家!