手里拿著錘子時眼里只能看到釘子
今天線上的應用出問題了。
問題現象是
待渲染的頁面一共要請求兩個接口。這兩個接口一直在請求,基本上要一分鐘多響應完成,但完成并不是正常顯示,而是返回500的錯誤服務器錯誤。 |
聽到PM反饋問題后,經驗主意上身,二話不說,上手開始分析。
第一步從線上服務器的日志開始入手。在線上日志查看時發現日志文件中最新的內容并不是附近的時間,而是一個小時前 -- 后續的日志都沒有輸出到文件中。
發現這個現象后,感覺日志輸出不了,可能是和磁盤空間有關, 使用 df 命令開始查看空間。
果然,Tomcat 所在的目錄,磁盤使用已經達到了100%。再切換回 Tomcat 日志目錄發現大量的日志文件,果斷把前面一些舊的已經數據分析統計過的刪除。應用開始正常。
此時以為已經解決了問題,在群里和相關同學說是因為磁盤滿導致的,一切OK。
中午吃個飯的時間,應用又出問題了,還是老樣子。心想剛清的磁盤,空間還有一些,就開始使用上一篇剛寫過的 jstack,打出 stackTrace 之后,分析內容中的Tomcat線程工作情況,又隔一段時間再打一個互相對比,自己感覺該比的都比了,也沒發現任何有阻塞或者死鎖的情況,此時應用的情況是偶爾一次頁面會渲染成功,但也是比較慢的,大部分時候都不成功。
以前遇到過一次頁面渲染慢是因為后臺存放到云上的文件在保存完之后,沒有進行 close 操作,把連接點滿了,導致后面的請求都超時,當時通過 jstack 發現了問題之后快速解決了問題。所以這一次因循老路,還按這個思路來分析。
線上服務是部署在四臺機器上,還分析了四臺機器上的日志,也沒看到請求的信息到達過其他機器上,所以一直在之前磁盤滿的那一臺機器上分析。
此時 QA 同學告知,另外三臺機器上的日志一直沒有刷出來,很長時間了。這時才想到可能是另外三臺機器的磁盤空間也滿了,日志輸出不出來,在請求分配到這些節點上時分導致頁面渲染不成功,而如果請求到達了第一臺刪除過的機器上,頁面會渲染。
把另外三臺機器的磁盤也清理了一下,果然,應用可能正常且快速的響應了。
這個問題分析時,在應用頁面渲染慢時,分析了第一臺機器的磁盤問題,之后就一根筋的順著性能響應這條路去分析了,一會 jstack, 一會看下 GC 的執行是否正常 ...
忘了請求會分發到另外三臺機器上,也沒有在清理第一臺機器磁盤時順便上去看一下。
真的是手里拿著錘子,眼里就只能看到釘子。 甚至有些內容,即使和過往經驗有類似的地方,也不見得就一定是同樣的問題。有時候真需要放下錘子仔細看看,不能埋頭就上啊。
想起之前暗時間的作者劉未鵬寫過一次這樣的經歷:
說當時和他老婆一起到銀行取錢。走到銀行門前,發現需要刷卡才能進去,刷了下銀行卡進去了。取完錢出來,未鵬拿了一張不是銀行卡的普通卡,刷了一次也把門打開了,這時他認定是這門鎖有問題,只有刷個卡就能進,不停的刷了好幾張卡。
這時他老婆提醒道:萬一是這門壞了呢,可能都不用卡。
未鵬伸手一推,門開了。
未鵬在寫這個經歷時說,有時候我們容易形成思維定勢,更愿意從自己熟悉的角度去考慮問題,而忽視本來已經暴露出的現象。
有些時候,遇到問題時,放下手里的錘子,站遠些看一看,可能會有新的認識。軟件開發中還有一條著名的橡皮鴨法則,就是在陷入自己的思路時,向放在桌上的橡皮鴨講一講,可能在講的過程中自己就明白了。不套用經驗,多搜集信息,再分析,而不陷入思維定勢中,也許才是解決問題的好方法。
【本文為51CTO專欄作者“侯樹成”的原創稿件,轉載請通過作者微信公眾號『Tomcat那些事兒』獲取授權】