我所經歷的一次Dubbo服務雪崩，這是一個漫長的故事

• 2019 年 11 月 13 日
• 筆記

這周本來是要寫一篇Dubbo源碼分析的，被突發事件耽擱了，下周有時間再補上。

這周，筆者經歷了一次服務雪崩。服務雪崩，聽到這個詞就能想到問題的嚴重性。是的，整個項目，整條業務線都掛了，從該業務線延伸出來的下游業務線也跟著涼了。筆者是連續三天兩夜的忙著處理問題，加起來睡眠時間不足5小時，今天才得以睡個好覺。但事故之後還有很多問題等著去處理。

其實這一天的到來我是有意料到的，但我以為會是數據量上升導致，實際卻是並發量先上升，而嚴重程度超出我的預料。問題出現那天，我們還在進行每周的技術分享會，結果運營推開會議室的大門傳來噩耗，頓時技術分享會變成了問題排查討論會，場面像極了一起加班解決Bug。

在一個處理用戶點擊廣告的高並發服務上找到了問題。看到服務列印的日記後我完全蒙了，全是jedis讀超時，Read time out！一直用的是亞馬遜的Redis服務，很難想像Jedis會讀超時。

看了服務的負載均衡統計，發現並發增長了一倍，從每分鐘3到4萬的請求數，增長到8.6萬，很顯然，是並發翻倍導致的服務雪崩。

服務的部署：

處理廣告點擊的服務：2台2核8g的實例，每台部署一個節點(服務)。下文統稱服務A

規則匹配服務(Rpc遠程調用服務提供者)：2個節點，2台2核4g實例。下文統稱服務B

還有其它的服務提供者，但不是影響本次服務雪崩的兇手，這裡就不列舉了。

從日記可以看出的問題：

一是遠程rpc調用大量超時，我配置的dubbo參數是，每個介面的超時時間都是3秒。服務提供者介面的實現都是快取級別的操作，3秒的超時理論上除了網路問題，調用不應該會超過這個值。在服務消費端，我配置每個介面與服務端保持10個長連接，避免共享一個長連接導致應用層數據包排隊發送和處理接收。

二是剛說的Jedis讀操作超時，Jedis我配置每個服務節點200個最小連接數的連接池，這是根據netty工作執行緒數配置的，即讀寫操作就算200個執行緒並發執行，也能為每個執行緒分配一個連接。這是我設置Jedis連接池連接數的依據。

三是文件句柄數達到上線。SocketChannel套接字會佔用一個文件句柄，有多少個客戶端連接就佔用多少個文件句柄。我在服務的啟動腳本上為每個進程配置102400的最大文件打開數，理論上目前不會達到這個值。服務A底層用的是基於Netty實現的http服務引擎，沒有限制最大連接數。

所以，解決服務雪崩問題就是要圍繞這三個問題出發。

第一次是懷疑redis服務扛不住這麼大的並發請求。估算廣告的一次點擊需要執行20次get操作從redis獲取數據，那麼每分鐘8w並發，就需要執行160w次get請求，而redis除了本文提到的服務A和服務B用到外，還有其它兩個並發量高的服務在用，保守估計，redis每分鐘需要承受300w的讀寫請求。轉為每秒就是5w的請求，與理論值redis每秒可以處理超過 10萬次讀寫操作已經過半。

由於歷史原因，redis使用的還是2.x版本的，用的一主一從，jedis配置連接池是讀寫分離的連接池，也就是寫請求打到主節點，讀請求打到從節點，每秒接近5w讀請求只有一個redis從節點處理，非常的吃力。所以我們將redis升級到4.x版本，並由主從集群改為分散式集群，兩主無從。別問兩主無從是怎麼做到的，我也不懂，只有亞馬遜清楚。

Redis升級後，理論上，兩個主節點，分槽位後請求會平攤到兩個節點上，性能會好很多。但好景不長，服務重新上線一個小時不到，並發又突增到了六七萬每分鐘，這次是大量的RPC遠程調用超時，已經沒有jedis的讀超時Read time out了，相比之前好了點，至少不用再給Redis加節點。

這次的事故是並發量超過臨界值，超過redis的實際最大qps（跟存儲的數據結構和數量有關），雖然升級後沒有Read time out! 但Jedis的Get讀操作還是很耗時，這才是罪魁禍首。Redis的命令耗時與Jedis的讀操作Read time out不同。

redis執行一條命令的過程是：

1、接收客戶端請求

2、進入隊列等待執行

3、執行命令

4、響應結果給客戶端

由於redis執行命令是單執行緒的，所以命令到達服務端後不是立即執行，而是進入隊列等待。redis慢查詢日記記錄slowlog get的是執行命令的耗時，對應步驟3，執行命令耗時是根據key去找到數據所在的記憶體地址這段時間的耗時，所以這對於key-value字元串類型的命令而言，並不會因為value的大小而導致命令耗時長。

為驗證這個觀點，我進行了簡單的測試。

分別寫入四個key，每個key對應的value長度都不等，一個比一個長。再來看下兩組查詢日記。先通過CONFIG SET slowlog-log-slower-than 0命令，讓每條命令都記錄耗時。

key_4的value長度比key_3的長兩倍，但get耗時比key_3少，而key_1的value長度比key_2短，但耗時比key_2長。

第二組數據也是一樣的，跟value的值大小無關。所以可以排除項目中因value長度過長導致的slowlog記錄到慢查詢問題。慢操作應該是set、hset、hmset、hget、hgetall等命令耗時比較長導致。

而Jedis的Read time out則是包括1、2、3、4步驟，從命令的發出到接收完成Redis服務端的響應結果，超時原因有兩大原因：

1、redis的並發量增加，導致命令等待隊列過長，等待時間長

2、get請求讀取的數據量大，數據傳輸時間長

所以將Redis從一主一從改為兩主之後，導致Jedis的Read time out的原因一有所緩解，分攤了部分壓力。但是原因2還是存在，耗時依然是問題。

Jedis的get耗時長導致服務B介面執行耗時超過設置的3s。由於dubbo消費端超時放棄請求，但是請求已經發出，就算消費端取消，提供者無法感知服務端超時放棄了，還是要執行完一次調用的業務邏輯，就像說出去的話收不回來一樣。

由於dubbo有重試機制，默認會重試兩次，所以並發8w對於服務b而言，就變成了並發24w。最後導致業務執行緒池一直被佔用狀態，RPC遠程調用又多出了一個異常，就是遠程服務執行緒池已滿，直接響應失敗。

問題最終還是要回到Redis上，就是key對應的value太大，傳輸耗時，最終業務程式碼拿到value後將value分割成數組，判斷請求參數是否在數組中，非常耗時，就會導致服務B介面耗時超過3s，從而拖垮整個服務。

模擬服務B介面做的事情，業務程式碼（1）。

/** * @author wujiuye * @version 1.0 on 2019/10/20 {描述：} */public class Match {      static class Task implements Runnable {        private String value;          public Task(String value) {            this.value = value;        }          @Override        public void run() {            for (; ; ) {                // 模擬jedis get耗時                try {                    Thread.sleep(10);                } catch (InterruptedException e) {                    e.printStackTrace();                }                // =====> 實際業務程式碼                long start = System.currentTimeMillis();                List<String> ids = Arrays.stream(value.split(",")).collect(Collectors.toList());                boolean exist = ids.contains("4029000");                // ====> 輸出結果，耗時171ms .                System.out.println("exist:" + exist + ",time:" + (System.currentTimeMillis() - start));            }        }    }      ;      public static void main(String[] args) {        // ====> 模擬業務場景，從快取中獲取到的字元串        StringBuilder value = new StringBuilder();        for (int i = 4000000; i <= 4029000; i++) {            value.append(String.valueOf(i)).append(",");        }        String strValue = value.toString();        System.out.println(strValue.length());        for (int i = 0; i < 200; i++) {            new Thread(new Task(strValue)).start();        }    }}

這段程式碼很簡單，就是模擬高並發，把200個業務執行緒全部耗盡的場景下，一個簡單的判斷元素是否存在的業務邏輯執行需要多長時間。把這段程式碼跑一遍，你會發現很多執行耗時超過1500ms，再加上Jedis讀取到數據的耗時，直接導致介面執行耗時超過3000ms。

這段程式碼不僅耗時，還很耗記憶體，沒錯，就是這個Bug了。改進就是將id拼接成字元串的存儲方式改為hash存儲，直接hget方式判斷一個元素是否存在，不需要將這麼大的數據讀取到本地，即避免了網路傳輸消耗，也優化了介面的執行速度。

由於並發量的增長，導致redis讀並發上升，Jedis的get耗時長，加上業務程式碼的缺陷，導致服務B介面耗時長，從而導致服務A遠程RPC調用超時，導致dubbo超時重試，導致服務B並發乘3，再導致服務B業務執行緒池全是工作狀態以及Redis並發又增加，導致服務A調用異常。正是這種連環效應導致服務雪崩。

最後優化分三步

一是優化數據的redis快取的結構，剛也提到，由大量id拼接成字元串的key-value改成hash結構快取，請求判斷某個id是否在快取中用hget，除了能降低redis的大value傳輸耗時，也能將判斷一個元素是否存在的時間複雜度從O(n)變為O(1)，介面耗時降低，消除RPC遠程調用超時。

二是業務邏輯優化，降低Redis並發。將服務B由一個服務拆分成兩個服務。這裡就不多說了。

三是Dubbo調優，將Dubbo的重試次數改為0，失敗直接放棄當前的廣告點擊請求。為避免突發性的並發量上升，導致服務雪崩，為服務提供者加入熔斷器，估算服務所能承受的最大QPS，當服務達到臨界值時，放棄處理遠程RPC調用。

（我用的是Sentinel，官方文檔傳送門：

https://github.com/alibaba/Sentinel/wiki/%E6%8E%A7%E5%88%B6%E5%8F%B0）

（Sentinel控制台）

所以，快取並不是簡單的Get，Set就行了，Redis提供這麼多的數據結構的支援要用好，結合業務邏輯優化快取結構。避免高並發介面讀取的快取value過長，導致數據傳輸耗時。同時，Redis的特性也要清楚，分散式集群相比單一主從集群的優點。反省img。

經過兩次的項目重構，項目已經是分散式微服務架構，同時業務的合理劃分讓各個服務之間完美解耦，每個服務內部的實現合理利用設計模式，完成業務的高內聚低耦合，這是一次非常大的改進，但還是有還多歷史遺留的問題不能很好的解決。同時，分散式也帶來了很多問題，總之，有利必有弊。

有時候就需要這樣，被項目推著往前走。在未發生該事故之前，我花一個月時間也沒想出困擾我的兩大難題，是這次的事故，讓我從一個短暫的夜晚找出答案，一個通宵讓我想通很多問題。

對於本次服務雪崩帶來的影響，我只能深感抱歉！說實話，我已經厭倦了這種賣力不討好的事情。