線上服務一直很穩定，最近忽然cpu使用率百分百，詭異問題排查

線上某服務一直運行很穩定，最近忽然就cpu百分百，rpc遠程調用所有失敗，並走了mock邏輯。重啓後，一個小時後問題又重現。因而dump線程棧信息，但不仔細看也看不出什麼問題。因而就有了一番排查歷程。

前一天，我dump線程棧信息後發現佔用cpu高的線程是阿里的限流組件sentinel，並根據線程棧信息知道，在sentinel控制檯會拉取該服務的qps統計信息。這個接口會讀取本地文件內容，由於qps信息是輸出到/root/logs/csp/目錄下的某個文件的，而且是用NIO方式讀取文件。所以我猜想是sentinel在某種條件下會觸發死循環bug，也就能解釋得清楚爲何cpu會出現百分百的使用率。

帶着這個猜想，我將限流功能去掉，覺得問題就能解決了，可是沒想到次日早上有看到這個問題。因而我先將該服務的其它節點重啓，留下一個節點，並將剩下的節點從註冊中心中剔除。可沒想到的是，註冊中心已經沒有這個節點了，應該是全部該服務的節點都與註冊中心失聯了，其它是由於重啓以後從新註冊到註冊中心的。

既然沒有註冊到註冊中心，其它服務調用直接走mock邏輯也解釋得通。繼續前一天的進度，我首先是查看文件句柄數是否打開不少，因而使用lsof查看，果真不出所料。

進程15567打開的文件句柄數20多萬，所以我更願意相信是sentinel讀取文件出現bug的猜想，由於我想起前一天限流功能尚未徹底去除，只是去除了限流配置。接着查看這個進程是否打開了/root/logs/csp目錄下的文件（這個目錄是從限流組件的源碼中找出來的）。

遺憾的是看不到每一個文件的打開數量。接着我用lsof -p 進程id命令查看下，該進程打開的文件句柄信息。

因而我發現打開最多的不是/root/logs/csp目錄下的文件，而是redis鏈接。這下只能將限流組件sentinel有bug的猜想去掉了，由於昨天去掉配置後，也並無看到sentinel線程佔用cpu太高的現象了，只能排除。繼續統計redis的socket打開數量。

確實對上了，文件句柄數達上限的問題確實是與redis-cluster有關。因而我使用redis-cli命令鏈接上redis服務，看下是否鏈接數增多了，是否與該進程持有的文件句柄數對得上。由於前一天我也發現某消息消費服務偶爾出現鏈接超時的狀況。

然而並未發現什麼異常，客戶端鏈接數與日常同樣。只能懸於此了。因而我又去分析線程棧信息，發現大量的dubbo線程處於wait狀態，且都是阻塞在歸還redis鏈接到鏈接池以及從鏈接池中申請鏈接這一步。

還有少幾個dubbo如今是runing狀態，緣由是這些線程走了內存緩存，我用aop攔截請求，命中內存緩存的不會往下走業務邏輯，也就不會用到redis。所以這些線程處理的請求是正常的。

那麼爲何cpu會百分百呢？大片的業務線程都已經被阻塞住了，都在wait狀態，究竟是什麼線程佔用如此高的cpu。因而我纔想到用top命令去查看。

看到兩個非業務相關的線程，佔用很是高的cpu，因而又回去琢磨線程棧信息，與top命令顯示的command列對得上的也就只有兩個垃圾回收線程。

因而就是jstat命令查看gc垃圾回收狀況。

連續使用jstat命令查看gc狀況，發現每次執行命令，大概是1秒多，fgc的次數就加1了。問題的真相已經很是接近。找到這裏，就是排查業務代碼了。

因爲使用了內存緩存，會致使full gc的狀況很正常，我首先想到兩點，一是緩存數據太多，二是緩存數據清理的定時任務執行失敗了。並且因爲以前該服務一直很穩定，猜想多是數據格式不正確觸發的bug，致使數據清理失敗，越積越多。可是看了代碼後，我是加了try-catch的，出異常也會移除緩存，只是清理時間間隔比較長，一個小時才清理一次。

到此，我就再也不往下分析了。去掉內存緩存是不可能的，只能計算業務所須要的內存，提高實例的內存。經過數據庫查詢，估算須要緩存的記錄數是四百多萬，本地寫了個測試用例，計算四百多萬記錄大概消耗700多m的內存，所以，只須要將機器的內存稍微提升一點就沒有問題了。

可是我想不通的是，redis鏈接文件句柄數爲何會如此高呢，不是用了鏈接池，是fgc影響了什麼嗎？STW也不至於致使redis文件句柄打開這麼多吧？若是您知道，很是但願您能留言幫我解答下疑惑，感激涕零！