某個舊版本業務功能中運行了一個失敗重試的job,因一位離職的同事編碼時未考慮周全出現死循環,致使線上從24日下午2點一直到27日晚9點持續3天一直在刷日誌。異常日誌內容以下:redis
二、事故過程分析:緩存
①、根據異常日誌內容,初步考慮爲redis中緩存的token失效了,後檢查token並與請求方token對比,發現token正確,故排除token過時緣由安全
②、經過grep命令查找更多日誌內容後,依然沒法顯示更多有用信息(包括調用入口,更多代碼中打印的日誌信息等),因而覈查全部可能的代碼入口,並依次打印相關日誌,結果均未打印有效信息。架構
③、考慮以前該服務已經接入公司自研的日誌鏈調用分析系統,前後根據日誌關鍵內容和traceid在系統中查詢,結果發現traceId的調用鏈沒法正常顯示,依舊沒法找到異常日誌準確的入口,後找到故障緣由後,架構組同事猜想多是由於該調用鏈一直未調用結束,致使沒法經過traceId來查找調用鏈。編碼
④、因爲持續重複調用同一個接口,開始覺得是安全問題懷疑被人刷接口(前段時間公司有進行安全驗證),後看到全部日誌內容均是由同一個線程所打印的,所以懷疑多是有死循環存在。後與同事確認,瞭解到舊版某個業務中有一個失敗訂單重試job,目前已經棄用了,理論上應該不存在問題,而後又找到該job的入口,使用grep命令查看第一行日誌,發現仍未打印日誌,因而排除了該job的入口。後來發現被迷惑了,由於該job是在7.24下午2點開始的,由於死循環該方法一直沒調用完,因此到27號查找該日誌內容時依然未打印。spa
⑤、後使用jstack命令經過線程名稱最終查找到異常代碼入口,肯定事故緣由是因爲舊版業務的job致使,線程
該job的部分代碼以下:日誌
能夠看到,最外層的for循環的終止條件只能依賴於xxList變量,而且token是在循環外層定義的(這也解釋了爲什麼日誌一直顯示token校驗失敗了,由於token是24號的,正常狀況token爲1小時更新一次),而在job執行過程當中,token過時了,所以後面的query方法返 回的code一直不爲0,因而進入死循環,致使一直刷日誌。code
三、事故解決:
找到問題後,重啓了1臺服務後觀察一段時間,發現日誌恢復正常,因而重啓剩餘2臺機器,並在es-job中將該job禁用。
四、事故影響分析:
因爲只是打印日誌,且日誌量不大,未對平臺核心相關服務產生明顯影響,但因爲重複請求服務方,致使對方機器磁盤爆滿後發現了該問題。
五、事故總結:
①、使用for循環時,必須確保循環終止條件能達到,避免產生死循環。
②、良好的日誌能有效提高問題定位的效率,有關日誌打印規範,請參考阿里巴巴日誌規約(http://www.cnblogs.com/dragonsuc/p/6937584.html)
③、對於已經棄用的業務和功能,注意一些舊的job可能產生的影響,若有必要須要中止。
④、儘可能經過多角度快速定位問題,好比重複日誌就要考慮是否有死循環,熟練使用jstack等命令快來速定位代碼。
若有其餘建議和意見,歡迎指出批評。