這個項目最初我是PM,當時要求集群達到60000tps,單服務器要能達到2000tps,這個要求說實話的確有些誇張,最終結果雖然沒這么高,但單台服務器主要流程的確能達到近1000tps,這不是重點。我負責的項目交付一期以后,交給另外一位同事繼續后續的二期的開發,這個項目后續在甲方重視程度很高,至今仍有大量人力在支持這個項目。有一天這個項目的PM給我打電話,說最近系統出現一個奇怪的現象,非常小的概率會出現500錯誤,一旦出現錯誤以后,再訪問都是500錯誤,只有重啟才能解決,cpu和內存使用率都非常的低,沒有任何的錯誤日志,他們已經分析了幾天了,一點兒思路也沒有,今天又出現了。
以前看這這樣一句話“所有沒有日志的問題定位都是耍流氓”,但是現實情況就是不耍流氓就不行,問題擺在面前。
6點吃過晚飯和同事一起到了客戶的辦公場所,因為這是我之前負責的項目,里面的流程和代碼我比較熟悉,但是一時也沒有思路,唯一的思路就是這個500頁面,靈光一現,能不能在這個500頁面里做文章,因為我知道在j2ee中會在request和session的attribute寫一些屬性,會不會這里有一些線索。於是我在這台出現500錯誤的jsp頁面里面加了一堆把request和session里所有的attribute都讀出來的代碼,這下子信息量就大了很多,發現了在attribute有一個error,一步步的推斷是底層的平台拋出的錯誤,再進一步結合代碼反編譯發現是我們使用的底層平台在使用線程變量的時候在異常處理的時候沒有將ThreadLocal的值清空導致后面再進來的請求讀取的是空對象,也也導致了NPE,這樣推測下我們找到了平台的同事一起分析,他們在Review代碼以后也承認有問題,很快他們修復了bug,至此再沒出現過。
這個問題本身從技術來講並沒有太多好玩的東西,但是讓我更加堅信問題總有解決的辦法,更加全面的掌握各種知識加上實踐會讓你在遇到問題有更多的機會會靈光一現。問題本身並沒有太多的技術含量,但是當你去解決的時候,你會發現如果沒有經驗和知識儲備的話,解決起來寸步難行。
有的人可能會問為什么NPE的日志為什么會被吃掉了,而不是打印在tomcat的默認的日志中,這是因為這個項目中把標准錯誤輸出和標准輸出都重定位到/dev/null這個垃圾桶中了.