前言
實(shí)際我們?cè)陂_發(fā)過程中琼娘，遇到最多的問題就是代碼bug導(dǎo)致數(shù)據(jù)異常這種情況峭弟，這種情況一般都可以靜態(tài)的查看代碼去進(jìn)行定位附鸽。但是問題產(chǎn)生不是我們能預(yù)料到的，預(yù)料到了的缺陷那可能是放棄治療了瞒瘸，所以這里我分享一個(gè)真實(shí)的非靜態(tài)定位bug的過程--一個(gè)服務(wù)器宕機(jī)讓測(cè)試頭皮發(fā)麻的問題坷备。
案件重現(xiàn)
場(chǎng)景1
頭天晚上提測(cè)完，第二天正是放松警惕的時(shí)候情臭，老實(shí)說測(cè)試告訴我服務(wù)器宕機(jī)的時(shí)候我是懵逼的省撑，怎么我們自測(cè)的好好的，到他們那服務(wù)器就掛了呢俯在。
Step1：
看了一下服務(wù)器環(huán)境竟秫，內(nèi)存使用量已經(jīng)超標(biāo)了，然后我們提出讓測(cè)試對(duì)測(cè)試服務(wù)器的內(nèi)存進(jìn)行擴(kuò)容跷乐。
step2：
結(jié)果沒有測(cè)試幾天肥败，服務(wù)器又宕機(jī)了，測(cè)試過程也真是坎坷愕提，宕機(jī)的還是他們的主測(cè)環(huán)境馒稍，然后我熟練的連上了他們的環(huán)境，一看是IO的問題浅侨，IO都占用100%了纽谒，這服務(wù)器能正常就有鬼了。這個(gè)時(shí)候最粗暴的方法就是加硬盤如输，橫向拓寬服務(wù)器的IO處理能力佛舱。但是服務(wù)器已經(jīng)裝好了，如果要把裝好的服務(wù)卸載裝到新的硬盤里面挨决，那么原先的數(shù)據(jù)就丟了请祖，不是良好的解決方案。
然后我們打開了服務(wù)器上tomcat的JMX看一下到底是哪個(gè)服務(wù)在過量打印日志信息脖祈。通過VisualVM這個(gè)工具肆捕，我們看到有個(gè)線程內(nèi)存分配很頻繁，每次申請(qǐng)的空間也較大盖高，然后找到對(duì)應(yīng)的開發(fā)人員讓其做一下修改慎陵。然后繼續(xù)定位，發(fā)現(xiàn)http請(qǐng)求的線程都黃了喻奥，都處于等待狀態(tài)席纽，正好符合頁(yè)面請(qǐng)求無響應(yīng)的現(xiàn)象。
然后我們只是更徹底的了解了問題撞蚕，但定位的思路又回到了原點(diǎn)润梯，所以這個(gè)時(shí)候就去看服務(wù)器上哪些服務(wù)占用IO過高了，在服務(wù)器上，有兩個(gè)應(yīng)用占用IO很高纺铭，一個(gè)是對(duì)象存儲(chǔ)的寇钉，還有一個(gè)是用于存儲(chǔ)日志信息的數(shù)據(jù)庫(kù)。對(duì)象存儲(chǔ)的IO占用高也不能算異常舶赔，畢竟要讀取圖片什么的扫倡，但是數(shù)據(jù)庫(kù)的IO占用那么高就有點(diǎn)異常了。
這個(gè)時(shí)候問題很清晰了竟纳，是日志服務(wù)在抽取日志信息到數(shù)據(jù)庫(kù)的過程中占用了服務(wù)器絕大部分IO撵溃，導(dǎo)致其他服務(wù)器請(qǐng)求數(shù)據(jù)庫(kù)得不到響應(yīng)。然后我們關(guān)掉了部分日志記錄锥累，服務(wù)器又回到正常狀態(tài)征懈。
場(chǎng)景2
step3：
好景不長(zhǎng)，服務(wù)器又宕機(jī)了揩悄，這次IO和內(nèi)存以及CPU都很正常卖哎，凡是可以監(jiān)控到的指標(biāo)都沒有出現(xiàn)異常情況。然后組件日志里面滿屏都是http請(qǐng)求超時(shí)的異常删性。
幸虧這次提測(cè)的時(shí)候測(cè)試已經(jīng)提前打開了JMX亏娜，我們可以更快的連上服務(wù)器。當(dāng)我看到大量http請(qǐng)求都處于黃色狀態(tài)的時(shí)候蹬挺。我百思不得其解维贺，因?yàn)槲覀兊姆?wù)本身不是具有大量并發(fā)http請(qǐng)求的服務(wù)炼邀，我懷疑有服務(wù)沒有及時(shí)釋放IO揖膜，后來看了代碼官边，發(fā)現(xiàn)基本上所有的代碼都是使用的restTemplate川背，IO是自動(dòng)釋放的，超時(shí)時(shí)間也有設(shè)置奴紧，理論上不會(huì)出現(xiàn)阻塞懂牧。
這個(gè)時(shí)候問題又回到了大量http請(qǐng)求阻塞了坤学，既然我們的服務(wù)不會(huì)有這么多請(qǐng)求用押，卻又出現(xiàn)了這么多并發(fā)請(qǐng)求肢簿，那肯定有個(gè)地方觸發(fā)了。我們只要找到它就行蜻拨。
我機(jī)制的同事池充，在我另外一臺(tái)閑置的虛擬機(jī)上，把數(shù)據(jù)庫(kù)關(guān)了缎讼，然后打開web頁(yè)面去操作了一會(huì)（打開F12）收夸，發(fā)現(xiàn)有個(gè)帶有刷新功能的頁(yè)面會(huì)觸發(fā)不少查詢，點(diǎn)擊次數(shù)的增加血崭，它的并發(fā)查詢數(shù)還會(huì)增加卧惜。
后來通過交流發(fā)現(xiàn)是前端設(shè)置了點(diǎn)擊那個(gè)tab頁(yè)會(huì)啟動(dòng)一個(gè)定時(shí)器厘灼，然后我們多次點(diǎn)擊這個(gè)tab也之后，定時(shí)器就會(huì)越來越多序苏，然后就成為了本次宕機(jī)的罪魁禍?zhǔn)住?/p>
定位思路改進(jìn)點(diǎn)
（1）上面的定位過程中有一個(gè)繞圈圈的過程手幢，其中一次服務(wù)器宕機(jī)我們看到IO異常之后捷凄，應(yīng)該直接去找那個(gè)占用IO的服務(wù)忱详，從它出發(fā)逆向推問題，而不是南轅北轍的去看tomcat里面的服務(wù)有沒有異常跺涤，因?yàn)殚_發(fā)JMX需要重啟tomcat匈睁，耗時(shí)較長(zhǎng)。
（2）在場(chǎng)景1中桶错，我們忽略了一個(gè)很嚴(yán)重的問題航唆，雖然我們關(guān)閉了日志服務(wù)，但是打開JMX的時(shí)候院刁，我們重啟了服務(wù)糯钙，有些問題在重啟的過程中暫時(shí)得到了解決。讓我們以為問題已經(jīng)被徹底解決退腥。
（3）第三次定位問題的過程中任岸，從一開始我就發(fā)現(xiàn)了是http請(qǐng)求阻塞的情況，但卻無從下手狡刘。實(shí)際上我們可以通過日志中的調(diào)用鏈去查看請(qǐng)求的源頭享潜，然后就不需要這種碰巧式的定位問題法了。
（4）數(shù)據(jù)庫(kù)連接狀態(tài)查看嗅蔬，select * from pg_stat_activity剑按，可以找到是哪些sql導(dǎo)致數(shù)據(jù)庫(kù)阻塞。
