[[385025]]

圖片來自 Pexels

我 8 點半左右到家，立馬上線入會......

重啟

我入會的時候，已經有同事在幫忙定位了，俗話說的好，重啟能解決 80% 的問題，如果重啟解決不了，那肯定是重啟的次數還不夠，呸，不對，重啟解決不了，就真的要去定位了。

事實證明，重啟后走一波壓測依然沒什么用，1000 個并發，平均響應時間在 3~4 秒，連續壓了幾次都是這樣的結果。

升級配置

重啟看來是無效了，進入第二個階段——升級配置，2 臺 4 核 8G 的實例升級到 6 臺 8 核 16G，數據庫的配置也翻了一倍，能用錢解決的問題，我們一般不會投入太多的人力!

事實證明，加配置也沒什么卵用，1000 個并發，壓測的平均響應時間還是在 3~4 秒。

有點意思，此時，我介入了。

查看監控

我上線之后，查看了一下監控，實例的 CPU、內存、磁盤、網絡 IO、JVM 堆內存使用情況好像都沒啥問題，這真是個頭疼的問題。

本地壓測

我們分成兩波同學，一波去準備本地壓測，一波繼續分析，經過本地壓測，我們發現，本地環境，單機，1000 個并發，妥妥的，毛問題都沒有，平均響應基本維持在幾百毫秒。

看來，確實跟服務本身沒有問題。

代碼走查

實在沒有辦法了，拿出代碼，一群大老爺們一起看代碼，研發同學給我們講解業務邏輯，當然，他已經被各位大佬給罵死了，寫的什么破代碼。

其實，在我介入之前，他們已經改過一波代碼了，有個地方把 redis 命令 scan 改成了 keys *，這里埋了個坑，但是，現在不是主要問題，后面我們會說。

代碼一路走讀下來，發現有很多的 redis 操作，還有個 for 循環里面在調 redis 的 get 命令，其他的都是常規的數據庫操作，而且都加了索引的。

所以，初步排查，數據庫這里應該是沒有什么問題，主要問題可能還是集中在 redis 這塊，調用太頻繁了。

加日志

代碼走查下來，除了那個 scan 改成了 keys *(這個我還不知道)，基本上沒有什么問題，加日志吧， 一小段一小段的加上日志，OK，重啟服務，壓測來一波。

當然了，結果沒有什么變化，分析日志。

通過日志，我們發現，調用 redis 的時候時而很快，時而很慢，看起來像是連接池不夠的樣子，也就是一批請求先行，一批請求在等待空閑的 redis 連接。

修改 redis 連接數

查看 redis 配置，用的是單機模式，1G 內存， 連接數默認的 8，客戶端還是比較老的 jedis，果斷改成 springboot 默認的 lettuce，連接數先調整為 50，重啟服務，壓一波。

平均響應時間從 3~4 秒降到了 2~3 秒，并不明顯，繼續加大連接數，因為我們是 1000 個并發，每個請求都有很多次 redis 操作，所以，肯定會有等待，這次我們把連接數直接干到了 1000，重啟服務，壓一波。

事實證明，并沒有明顯地提升。

再次查看日志

此時，已經沒有什么好的解決辦法了，我們再次回到日志中，查看 redis 相關操作的時間，發現 99% 的 get 操作都是很快返回的，基本上是在 0~5 毫秒之間，但是，總有那么幾個達到了 800~900 毫秒才返回。

我們以為 redis 這塊沒什么問題了。但是，壓測了好幾次，時間一直提不上去。

很無奈了，此時，已經半夜 3 點多了，領導發話，把 XX 云的人喊起來。

云排查

最后，我們把 XX 云相關的人員喊起來一起排查問題，當然，他們是不情愿的，但是，誰讓我們給錢了呢!

XX 云的負責人，把 redis 的專家搞起來，幫我們看了下 redis 的指標，最后，發現是 redis 的帶寬滿了，然后觸發了限流機制。

他們臨時把 redis 的帶寬增大三倍，讓我們再壓測一波。握了顆草，平均響應時間一下子降到了 200~300 毫秒!!!!

真的是握了顆草了，這就有點坑了，你限流就算了，帶寬滿了也不報警一下的么......

這真是個蛋疼的問題。到這里，我們以為問題就這樣解決了，領導們也去睡覺了!

上生產

既然問題原因找到了，那就上生產壓一波吧!我們讓 XX 云的專家把生產的帶寬也增大了三倍大小。

從生產提交拉一個 hotfix 分支，關閉簽名，重啟服務，壓測走一波。完蛋，生產環境更差，平均響應時間在 5~6 秒。

測試環境我們是改了連接池配置的，生產環境還是 jedis，改之，走一波。并沒有什么實際作用，還是 5~6 秒。

真是個蛋疼的問題。

查看監控

查看 XX 云中 redis 的監控，這次帶寬、流控都是正常的。

這次不正常的變成了 CPU，redis 的 CPU 壓測的時候直接飆到了 100%，導到應用響應緩慢。

再次喚醒 XX 云 redis 專家

已經凌晨四點多了，大家已經沒什么思路了，XX 云的 redis 專家，你給我再起來!

再次喚醒 XX 云的 redis 專家，幫我們分析了下后臺，發現 10 分鐘內進行了 14 萬次 scan......

萬惡的 scan

詢問研發人員哪里用到了 scan(前面他們改的，我不知道)，發現，每次請求都會調用 scan 去拿某個前綴開頭的 key，每次掃描 1000 條數據，查看 redis 鍵總數，大概有 11 萬條。

也就是說，一個請求就要 scan 100 次，1000 并發，大概就是 10 幾萬次 scan。

我們知道，redis 中 scan 和 keys * 是要進行全表掃描的，非常消耗 CPU，14 萬次 scan 操作，直接讓 CPU 上天了。

為什么測試環境 CPU 沒有上天呢?

對比了下，測試環境和生產環境 redis 的鍵總數，測試環境只有 900 個 key，每次請求也就 scan 一次或者 keys * 一次，毛線問題都沒有。

為什么生產環境有這么多 key?

詢問研發人員，為什么生產環境有這么多 key，沒有設置過期時間嗎?

研發人員說設置了的，是另一個同事寫的代碼，打開代碼，真是一段魔性的代碼，具體代碼我就不方便貼出來了，里面有根據條件判斷要不要設置過期時間，經過分析，大部分情況下，都沒有設置過期時間成功。

當前解決辦法

此時，已經凌晨 4 點半了，雖然大家還很興奮，但是，經過領導決策，暫時先不動了。

因為，目前 A 系統已經暫停調用 B 系統了，所以，此時 B 系統可以說流量幾乎為 0 了。

我們白天再分兩個階段來修復這個問題：

• 第一步，先清理掉生產環境 redis 的數據，只保留一小部分必要的數據。
• 第二步，修改 scan 某前綴開頭的數據，改成 hash 存儲，這樣可以減少掃描的范圍。

好了，本次生產事故排查就到這里了。

總結

本次生產事件跟以往遇到的事件都略有不同，大概總結一下：

• 以往都是應用服務本身的 CPU、內存、磁盤、JVM 這些問題，redis 的帶寬和限流還是第一次遇見。
• 上了 XX 云以后，很多東西還沒有弄得熟練，包括監控指標這些，還需要慢慢摸索。
• redis 一定要禁用掉 keys 和 scan 命令，且大部分 key 應該設置過期時間!

好了，本次事件大概就寫這么多，后續有新的情況我也會繼續跟進的，當然，最好不要有新的情況!

作者：彤哥

編輯：陶家龍

出處：轉載自公眾號彤哥讀源碼