記一次生產事故：30萬單就這樣沒了！

背景

你好，我是彤哥。

昨天晚上下班回家，在地鐵上，老大忽然打來電話，B系統生產環境響應緩慢，影響了A系統的使用，幾萬小哥收不了單，大概有30萬單卡住了，你去幫忙定位一下。

我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點多了，領導發話，把華爲雲的人喊起來。

華爲雲排查

最後，咱們把華爲雲相關的人員喊起來一塊兒排查問題，固然，他們是不情願的，可是，誰讓咱們給錢了呢^^

華爲雲的負責人，把redis的專家搞起來，幫咱們看了下redis的指標，最後，發現是redis的帶寬滿了，而後觸發了限流機制。

他們臨時把redis的帶寬增大三倍，讓咱們再壓測一波。

握了顆草，平均響應時間一會兒降到了200~300毫秒！！！！

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

這真是個蛋疼的問題。

到這裏，咱們覺得問題就這樣解決了，領導們也去睡覺了~~

上生產

既然問題緣由找到了，那就上生產壓一波吧~

咱們讓華爲雲的專家把生產的帶寬也增大了三倍大小。

從生產提交拉一個hotfix分支，關閉簽名，重啓服務，壓測走一波。

完蛋，生產環境更差，平均響應時間在5~6秒。

測試環境咱們是改了鏈接池配置的，生產環境仍是jedis，改之，走一波。

並無什麼實際做用，仍是5~6秒。

真是個蛋疼的問題。

查看監控

查看華爲雲中redis的監控，此次帶寬、流控都是正常的。

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

再次喚醒華爲雲redis專家

已經凌晨四點多了，你們已經沒什麼思路了，華爲雲的redis專家，你給我再起來！

再次喚醒華爲雲的redis專家，幫咱們分析了下後臺，發現10分鐘內進行了14萬次scan~~

關注公主號彤哥讀源碼，查看更多幹貨好文！

萬惡的scan

詢問研發人員哪裏用到了scan（前面他們改的，我不知道），發現，每次請求都會調用scan去拿某個前綴開頭的key，每次掃描1000條數據，查看redis鍵總數，大概有11萬條，也就是說，一個請求就要scan100次，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存儲，這樣能夠減小掃描的範圍。

好了，本次生產事故排查就到這裏了，後續，彤哥，也會繼續跟進的。

總結

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

1. 以往都是應用服務自己的CPU、內存、磁盤、JVM這些問題，redis的帶寬和限流仍是第一次碰見；
2. 上了華爲雲之後，不少東西尚未弄得熟練，包括監控指標這些，還須要慢慢摸索；
3. redis必定要禁用掉keys和scan命令，且大部分key應該設置過時時間！

好了，本次事件大概就寫這麼多，後續有新的狀況彤哥也會繼續跟進的，固然，最好不要有新的狀況^^