引言

作為後端開發人員，對Redis肯定不陌生，它是一款基于記憶體的資料庫，讀寫速度非常快。在愛奇藝海外後端的項目中，我們也廣泛使用Redis，主要用于緩存、消息隊列和分布式鎖等場景。最近在對一個老項目使用的docker鏡像版本更新過程中碰到一個奇怪的問題，發現項目更新到高版本鏡像後，通路Redis會出現很多逾時錯誤，而降回之前的鏡像版本後問題也随之消失。經過排查，最終定位問題元兇是一個涉及到Lettuce、Redis、Netty等多塊内容的代碼bug。在問題解決過程中也對相關元件的工作方式有了更深一步的了解。以下就對“捉蟲”過程中的問題分析和排查過程做一個詳細的介紹。

背景

我們的技術棧是業界常見的Spring Cloud全家桶。有問題的項目是整個微服務架構中的一個子服務，主要負責為用戶端提供包括節目詳情、劇集清單和播放鑒權等内容相關的web服務。由于節目、劇集、演員等大部分領域實體變更頻率不高，我們使用三主三從的Redis叢集進行緩存，将資料分片管理，以便儲存更多内容。

項目中通路Redis的方式主要有兩種，一種是直接使用Spring架構封裝的RedisTemplete對象進行通路，使用場景是對redis中的資料進行手動操作。另外一種方式是通過自研的緩存架構間接通路，架構内部會對緩存内容進行管理，主要包含二級緩存，熱key統計，緩存預熱等進階功能。

通過RedisTemplete通路：

通過自研緩存架構通路。如下圖，加上@CreateCache注解的對象被聲明為緩存容器，在項目啟動時架構會利用Redis的釋出訂閱機制，自動将遠端Redis二級緩存中的熱點資料同步到本地。并支援配置資料緩存的有效期、本地緩存數量等屬性。另外架構本身也提供了讀寫接口供使用方通路緩存資料。

問題現象

更新了鏡像版本後，應用正常啟動後會出現大量通路Redis逾時錯誤。在觀察了CPU、記憶體和垃圾回收等方面的正常監控後，并沒有發現明顯異常。隻是在項目啟動初期會有較多的網絡資料寫入。這實際上是之前提到的緩存預熱邏輯，是以也在預期之内。

由于項目本身存在兩種通路方式，不同環境下Redis伺服器架構也不同，為了固定問題場景，我們進行了一番條件測試，發現了一些端倪：

低版本鏡像上RedisTemplete和緩存架構通路Redis叢集均正常。
高版本鏡像上RedisTemplete通路Redis叢集正常，緩存架構通路Redis叢集逾時。項目啟動一段時間後架構通路恢複正常。
低版本和高版本鏡像中RedisTemplete和緩存架構通路Redis單機均正常

根據以上現象不難推斷出，問題應似乎出現在緩存架構通路Redis叢集的機制上。結合項目啟動一段時間後會恢複正常的特點，猜測應該和緩存預熱流程有關。

排查過程

複現case

查閱代碼後發現自研的緩存架構沒有通過Spring通路Redis，而是直接使用了Sping底層的Redis用戶端—— Lettuce。剔除了無關的業務代碼後，我們得到了一個可以複現問題的最小case，代碼如下：

整個case模拟的就是緩存的預熱場景，主要運作流程如下：

服務（節點3）啟動後發送新節點上線的ONLINE消息
其他節點（節點1,2）收到ONLINE消息後，将本地緩存的熱key打包
其他節點（節點1,2）發送包含本機熱key的HOTKEY消息
新節點（節點3）收到包含熱key的HOTKEY消息
新節點（節點3）根據收到的熱key反查redis擷取value值，并緩存到本地

在根據熱key反查Redis的方法中也加了日志，以顯示反查操作的執行時間（省略部分無關代碼）。

運作上述代碼後，我們看看控制台實際的輸出結果：

可以看到，應用在啟動後正常收到了Redis的HOTKEY消息并執行反查操作。然而，大量的反查請求在1秒後仍未擷取到結果。而源碼中請求future的逾時時間設定也是1秒，即大量的Redis get請求都逾時了。

一般情況下請求逾時的原因有兩個，要麼是請求沒有到達服務端，要麼是響應沒有回到用戶端。為了定位原因，我們在應用主控端上檢視與Redis叢集連接配接的通信情況，如下：

結果發現，本機與redis叢集的3個分片共建立了6個連接配接，其中一個tcp連接配接的接收隊列内容一直不為空，這說明該連接配接的響應資料已經到達本機socket緩沖區，隻不過由于某種原因用戶端程式沒有消費。作為對比我們在低版本鏡像上啟動後同樣觀察連接配接情況，發現不存在資料積壓的情況。

排查至此我們發現緩沖區的資料積壓很可能就是造成反查請求逾時的原因，明白了這一點後，我們開始思考：

連接配接緩沖區中的資料應該由誰來消費？
每個連接配接的作用是什麼？
為什麼隻有一個連接配接出現了資料積壓情況？
為什麼積壓情況隻在高版本的鏡像中出現？
為什麼通過Spring通路Redis就不會出現逾時問題？

深度分析

要回答以上問題，首先要了解Lettuce的工作原理，重點是其底層是如何通路Redis叢集的。

根據官網介紹，Lettuce 底層基于 Netty 的NIO模型實作，隻用有限的線程支援更多的 Redis 連接配接，在高負載情況下能更有效地利用系統資源。

我們簡要回顧一下Netty的工作機制。Netty中所有I/O操作和事件是由其内部的核心元件EventLoop負責處理的。Netty啟動時會根據配置建立多個EventLoop對象，每個Netty連接配接會被注冊到一個EventLoop上，同一個EventLoop可以管理多個連接配接。而每個EventLoop内部都包含一個工作線程、一個Selector選擇器以及一個任務隊列。

當用戶端執行連接配接建立或注冊等操作時，這些動作都會以任務的形式送出到關聯EventLoop的任務隊列中。每當連接配接上發生I/O事件或者任務隊列不為空時，其内部的工作線程（單線程）會輪詢地從隊列中取出事件執行，或者将事件分發給相應的事件監聽者執行。

在Lettuce架構中，與Redis叢集的互動由内部的RedisClusterClient對象處理。項目啟動時，RedisClusterClient會根據配置擷取所有主從節點資訊，并嘗試連接配接每個節點以擷取節點metadata資料，然後釋放連接配接完成初始化。随後，RedisClusterClient會按需連接配接各個節點。RedisClusterClient的連接配接分為主連接配接和副連接配接兩種。由用戶端顯示建立的連接配接是主連接配接，用于執行無需路由的指令，如auth/select等。而由client内部根據路由規則隐式建立的連接配接是副連接配接，用于執行需要根據slot路由的指令，例如常見的get/set操作。對于Pub/Sub釋出訂閱機制，為了確定訂閱者可以實時接收到釋出者釋出的消息，Lettuce會單獨維護一個專用于事件監聽的連接配接。

是以我們之前觀察到的6個TCP連接配接，實際上包含了1個叢集主連接配接、3個副連接配接、1個用于事件釋出的pub連接配接（由TestService聲明的statefulRedisPubSubConnection）以及1個用于訂閱的sub連接配接。所有這些連接配接都會被注冊到Netty的EventLoop上進行管理。

EventLoop機制的核心功能是多路複用，這意味着一個線程可以處理多個連接配接的讀寫事件。但是要實作這一點的前提是EventLoop線程不能被阻塞，否則注冊在該線程上的各個連接配接的事件将得不到響應。由此我們可以推測，如果socket緩沖區出現積壓，可能是某些原因導緻socket連接配接對應的 EventLoop 線程被阻塞，使其無法正常響應可讀事件并讀取緩沖區資料。

為了驗證猜測，我們在日志中列印線程資訊做進一步觀察。

結果發現大部分逾時都發生在同一個EventLoop線程上(Lettuce的epollEventLoop-9-3線程)，那這個線程此刻的狀态是什麼呢？我們可以通過診斷工具檢視線程堆棧，定位阻塞原因。

Arthas排障

這裡我們利用阿裡arthas排障工具的thread指令檢視線程狀态和堆棧資訊。

從堆棧資訊可以看出，Lettuce一共建立了3個Netty EventLoop線程，其中9-3處在TIMED_WAITTING狀态，該線程亦是Pub/Sub消息的的監聽線程，阻塞在了RedisLettucePubSubListener對象接收消息更新熱key的get方法上。

定位原因

通過Arthas排障我們了解到，原來Lettuce是在Netty的EventLoop線程中響應Pub/Sub事件的。由此我們也基本定位了緩沖區的積壓原因，即在RedisLettucePubSubListener中執行了阻塞的future get方法，導緻其載體EventLoop線程被阻塞，無法響應與其Selector關聯連接配接的io事件。

為什麼Pub/Sub事件會和其他連接配接的io事件由同一個EventLoop處理呢？通過查閱資料，發現Netty對連接配接進行多路複用時，隻會啟動有限個EventLoop線程（預設是CPU數*2）進行連接配接管理，每個連接配接是輪詢注冊到 EventLoop上的，是以當EventLoop數量不多時，多個連接配接就可能會注冊到同一個io線程上。

Netty中EventLoop線程數量計算邏輯

Netty注冊EventLoop時的輪訓政策

結合出問題的場景進一步分析，一共有3個EventLoop線程，建立了6個連接配接，其中 Pub/Sub 連接配接的建立優先級高于負責資料路由的副連接配接，是以必然會出現一個副連接配接和 Pub/Sub 連接配接注冊到同一個 EventLoop 線程上的情況。而我們的程式會通路大量的key，當key被路由到Pub/Sub的共享線程上時，由于此時線程被Pub/Sub的回調方法阻塞，即使緩沖區中有資料到達，也會導緻與該 EventLoop 綁定的副連接配接上的讀寫事件無法被正常觸發。

釋出訂閱回調方法阻塞導緻EventLoop線程阻塞

針對這種應用場景Lettuce官網上也有專門提醒：https://lettuce.io/core/release/reference/index.html

即不要在Pub/Sub的回調函數中執行阻塞操作。

另外還有一點需要額外說明，就是關于 EventLoop 的數量。由于我們并沒有主動配置，一般情況下Netty 會建立 CPU 數量的兩倍的 EventLoop。在我們的測試程式中，宿主環境是雙核，理論上應該建立4個 EventLoop。但觀察到實際的 EventLoop 數量卻隻有3個。這是因為 Lettuce 架構對 Netty 的邏輯進行了調整，要求建立的 EventLoop 數量等于 CPU 核數，且不少于3個。

Lettuce中的io線程數量計算邏輯。

這點在官方文檔中也有說明。

解決方案

原因定位後，解決方案也呼之欲出。有兩種方法：

增加io線程

增加Lettuce io線程數量，使Pub/Sub連接配接和其他連接配接可以注冊到不同的EventLoop中。具體設定方式也有兩種：

在lettuce提供的ClientResources接口中指定io線程數量

由于Lettuce底層用的Netty，也可以通過配置io.netty.eventLoopThreads參數來指定Netty中EventLoop的數量。為了快速驗證效果，我們在逾時執行個體上配置該參數後重新開機，發現問題果然消失，也進一步證明了的确是該原因導緻了通路逾時。

異步化

比較優雅的方式是不要在nio線程中執行阻塞操作，即将處理Pub/Sub消息的過程異步化，最好放到獨立的線程中執行，以盡早釋放Netty的EventLoop資源。我們熟悉的Spring-data-redis架構就是這麼做的。

Spring-data-redis的做法是每次收到消息時都新啟動新線程處理。

思考

盡管問題已經解決，但之前還有幾個遺留的疑問沒有解答。經過一番研究，我們也找到了答案。

為什麼低版本鏡像沒問題？

在之前的分析中，我們提到了因為 EventLoop 線程數量過少導緻線程阻塞。高版本的執行個體中 EventLoop 線程數量為 3，那麼低版本的情況呢？通過Arthas 檢視，發現低版本 Lettuce 的 EventLoop 數量是 13，遠遠超過了高版本的數量。這表示在低版本環境中，Pub/Sub 連接配接和其他連接配接會注冊到不同的 EventLoop 上，即使 Pub/Sub 處理線程被阻塞，也不會影響到其他連接配接讀寫事件的處理。

高版本鏡像最大線程編号9-3

低版本鏡像最大線程編号9-13

為什麼低版本的鏡像會建立更多的 EventLoop 呢？這其實是 JDK 的一個坑。早期的 JDK 8 版本（8u131 之前）存在docker環境下Java擷取cpu核心數不準确的問題，會導緻程式拿到的是主控端的核數。

(https://blogs.oracle.com/java/post/java-se-support-for-docker-cpu-and-memory-limits)

檢視低版本鏡像的jdk版本是8u101，應用主控端的核數是16，也就是說，低版本應用誤拿到了主控端的核數16，是以會将每個連接配接注冊到一個獨立的EventLoop上，進而避免了阻塞的發生。換句話說，之是以低版本鏡像沒問題，其實是程式在錯誤的環境下擷取到錯誤的數值，卻得到了正确的結果，負負得正了。至于為什麼最大線程号是 13 ，這是由于我們的 Redis 叢集配置了兩個域名，如下圖所示。

在 RedisClusterClient 初始化時，會分别對域名（2）、所有叢集節點（6）、Pub/Sub 通道（1）、叢集主連接配接（1）、副連接配接（3）進行連接配接建立，加起來一共正好是 13 個。

為什麼高版本通過Spring通路Redis為什麼不會出現逾時問題？

原始項目通路Redis有Spring和緩存架構兩種方式。前文中提到的所有 EventLoop 都是由自研緩存架構維護的 RedisClusterClient 對象建立的。而Spring 容器會使用單獨的 RedisClusterClient 對象來建立Redis連接配接。在 Lettuce 中，每個 RedisClusterClient 對象底層都對應着不同的 EventLoopGroup。也就是說，Spring 建立的Redis連接配接一定不會和緩存架構的連接配接共用同一個 EventLoop。是以即使緩存架構所在的 EventLoop 線程被阻塞，也不會影響到 Spring 連接配接的事件響應。

為什麼高版本鏡像通路單機Redis沒問題？

與RedisClusterClient通路Redis叢集時會建立多個主副連接配接不同，通路單機Redis時Lettuce使用的RedisClient隻會建立1個連接配接。再加上獨立的Pub/Sub連接配接，相當于是2個連接配接注冊到3個EventLoop上，避免了沖突。

總結

本文從實際工作中遇到的一個Redis通路逾時問題出發，探究背後Spring、Lettuce和Netty的工作原理，并利用Arthas等調試工具，分析了EventLoop線程對連接配接處理的重要性，以及在處理Pub/Sub事件時避免阻塞操作的必要性。通過觀察不同版本環境下的行為差異，加深了對JDK版本和程式環境适配的了解，為今後排查類似問題積累了寶貴經驗。

參考資料

[1]https://lettuce.io/core/5.3.7.RELEASE/reference/index.html

[2]https://docs.spring.io/spring-data/redis/reference/redis/pubsub.html

[3]https://github.com/TFdream/netty-learning/issues/22

[4]https://github.com/alibaba/jetcache/blob/master/docs/CN/RedisWithLettuce.md

[5]https://arthas.aliyun.com/doc/thread.html

[6]https://blogs.oracle.com/java/post/java-se-support-for-docker-cpu-and-memory-limits

作者:海外技術産品團隊

來源-微信公衆号:愛奇藝技術産品團隊

出處:https://mp.weixin.qq.com/s/cIVZ6VoNQqF0HFee9psfVQ

一次Redis通路逾時的“捉蟲”之旅

引言

背景