大家好，我們最近業務量暴漲，導致我最近一直 TM 人傻了。前幾天晚上，發現由於業務壓力激增，某個核心微服務新擴容起來的幾個實例，在不同程度上，出現了 Redis 連接失敗的異常：
org.springframework.data.redis.RedisConnectionFailureException: Unable to connect to Redis; nested exception is io.lettuce.core.RedisConnectionException: Unable to connect to redis.production.com
at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$ExceptionTranslatingConnectionProvider.translateException(LettuceConnectionFactory.java:1553) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$ExceptionTranslatingConnectionProvider.getConnection(LettuceConnectionFactory.java:1461) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.connection.lettuce.LettuceConnection.doGetAsyncDedicatedConnection(LettuceConnection.java:1027) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.connection.lettuce.LettuceConnection.getOrCreateDedicatedConnection(LettuceConnection.java:1013) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.connection.lettuce.LettuceConnection.openPipeline(LettuceConnection.java:527) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.connection.DefaultStringRedisConnection.openPipeline(DefaultStringRedisConnection.java:3245) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at jdk.internal.reflect.GeneratedMethodAccessor319.invoke(Unknown Source) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
at org.springframework.data.redis.core.CloseSuppressingInvocationHandler.invoke(CloseSuppressingInvocationHandler.java:61) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at com.sun.proxy.$Proxy355.openPipeline(Unknown Source) ~[?:?]
at org.springframework.data.redis.core.RedisTemplate.lambda$executePipelined$1(RedisTemplate.java:318) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:222) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:189) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:176) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.core.RedisTemplate.executePipelined(RedisTemplate.java:317) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.core.RedisTemplate.executePipelined(RedisTemplate.java:307) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.core.RedisTemplate$$FastClassBySpringCGLIB$$81812bd6.invoke(<generated>) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
//省略一些堆棧
Caused by: org.springframework.dao.QueryTimeoutException: Redis command timed out
at org.springframework.data.redis.connection.lettuce.LettuceConnection.closePipeline(LettuceConnection.java:592) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
... 142 more同時，也有業務調用 Redis 命令超時的異常：
org.springframework.data.redis.connection.RedisPipelineException: Pipeline contained one or more invalid commands; nested exception is org.springframework.data.redis.connection.RedisPipelineException: Pipeline contained one or more invalid commands; nested exception is org.springframework.dao.QueryTimeoutException: Redis command timed out
at org.springframework.data.redis.connection.lettuce.LettuceConnection.closePipeline(LettuceConnection.java:594) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.connection.DefaultStringRedisConnection.closePipeline(DefaultStringRedisConnection.java:3224) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at jdk.internal.reflect.GeneratedMethodAccessor198.invoke(Unknown Source) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
at org.springframework.data.redis.core.CloseSuppressingInvocationHandler.invoke(CloseSuppressingInvocationHandler.java:61) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at com.sun.proxy.$Proxy355.closePipeline(Unknown Source) ~[?:?]
at org.springframework.data.redis.core.RedisTemplate.lambda$executePipelined$1(RedisTemplate.java:326) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:222) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:189) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:176) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.core.RedisTemplate.executePipelined(RedisTemplate.java:317) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.core.RedisTemplate.executePipelined(RedisTemplate.java:307) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.data.redis.core.RedisTemplate$$FastClassBySpringCGLIB$$81812bd6.invoke(<generated>) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.3.7.jar!/:5.3.7]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:779) ~[spring-aop-5.3.7.jar!/:5.3.7]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.7.jar!/:5.3.7]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750) ~[spring-aop-5.3.7.jar!/:5.3.7]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) ~[spring-aop-5.3.7.jar!/:5.3.7]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.7.jar!/:5.3.7]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750) ~[spring-aop-5.3.7.jar!/:5.3.7]
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692) ~[spring-aop-5.3.7.jar!/:5.3.7]
at org.springframework.data.redis.core.StringRedisTemplate$$EnhancerBySpringCGLIB$$c9b8cc15.executePipelined(<generated>) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
//省略一部分堆棧
Caused by: org.springframework.data.redis.connection.RedisPipelineException: Pipeline contained one or more invalid commands; nested exception is org.springframework.dao.QueryTimeoutException: Redis command timed out
at org.springframework.data.redis.connection.lettuce.LettuceConnection.closePipeline(LettuceConnection.java:592) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
... 142 more
Caused by: org.springframework.dao.QueryTimeoutException: Redis command timed out
at org.springframework.data.redis.connection.lettuce.LettuceConnection.closePipeline(LettuceConnection.java:592) ~[spring-data-redis-2.4.9.jar!/:2.4.9]
... 142 more我們的 spring-data-redis 的配置是：
spring:
redis:
host: redis.production.com
port: 6379
# 命令超時
timeout: 3000
lettuce:
pool:
max-active: 128
max-idle: 128
max-wait: 3000這些請求雖然在第一次請求發送到的實例失敗了，但是我們有重試的機制，請求最後還是成功了。但是比正常的請求多了 3s，這部分請求佔了所有請求的 3% 左右。
從異常堆棧上面可以看出，異常的根源都是 redis 命令超時，但是為何建立 Redis 連接的時候，也會有 Redis 命令執行呢？
lettuce 建立連接的流程
我們的 Redis 訪問，使用的是 spring-data-redis + Lettuce 連接池。默認情況下，Lettuce 中的 Redis 連接建立的流程是：
- 建立 TCP 連接
- 進行必要的握手：
- 針對 Redis 2.x ~ 5.x 的版本：
1. 如果需要用戶名密碼，則發送用戶名密碼信息
2. 如果開啟了連接使用前心跳，則發送 PING - 針對 Redis 6.x 的版本：6.x 之後引入了新命令 HELLO，使用這個命令來統一初始化 Redis 連接：REDIS HELLO，這個命令參數中可以帶用戶名與密碼，完成驗證。
針對 Redis 2.x ~ 5.x 的版本，我們可以配置是否在啟用連接前發送 PING 心跳，默認為是：
ClientOptions
public static final boolean DEFAULT_PING_BEFORE_ACTIVATE_CONNECTION = true;我們使用的 Redis 版本是最新的 6.x，所以在建立連接，握手的階段，一定需要發送一個 HELLO 命令，並等待響應成功才算連接創建成功。
那麼為何這個簡單的命令也會超時呢？
通過 JFR 查看 Redis 命令壓力
我們的項目中 redis 操作是通過 spring-data-redis + Lettuce 連接池，啟用並且增加了關於 Lettuce 命令的 JFR 監控，可以參考我的這篇文章：這個 Redis 連接池的新監控方式針不戳~我再加一點佐料，截至目前我的 pull request 已經合併，這個特性會在 6.2.x 版本發布。我們看下出問題時間附近的 Redis 命令採集，如下圖所示：
可以看出，這時候 Redis 壓力還是比較大的（圖中的 firstResponsePercentiles 的單位是微秒）。我們這個時候，有 7 個實例，這個實例時剛啟動的，壓力相對於其他實例還比較小，就已經出現了連接命令超時。而且我們這裡只截取了 HGET 命令，還有 GET 命令執行的次數和 HGET 是同一量級的，然後剩下其他的命令加起來相當於 HGET 的一半。這時候從客戶端看，發往 Redis 的命令的 QPS 已經超過了百萬。
從 Redis 的監控來看，壓力確實有一些，可能會造成某些命令等待過長時間導致超時異常。
優化思路思考
我們先明確一點，針對 spring-data-redis + lettuce，如果我們沒有使用需要獨佔連接的命令（包括 Redis 事務以及 Redis Pipeline），那麼我們不需要連接池，因為 lettuce 是異步響應式的，對於可以使用共享連接的請求，都會使用同一個實際的 redis 連接進行請求，不需要連接池。但是這個微服務中，使用了大量的 pipeline 命令來提高查詢效率。如果我們不使用連接池，那麼會導致頻繁的連接關閉與創建（每秒幾十萬個），這樣會嚴重降低效率。雖然官網說，lettuce 不需要連接池，但是這是在你沒有使用事務以及 Pipeline 的情況下。
首先，Redis 擴容：我們的 Redis 部署在公有雲上，如果擴容也就是提高機器配置，下一個更高的配置指標相對於當前多了一倍，成本也是高了差不多一倍。目前只有在瞬時壓力的時候，會出現少於 3% 的請求失敗並重試下一實例，最後還是成功，針對這個對 Redis 進行擴容，從成本考慮並不值得。
然後，對於壓力過大的應用，我們是有動態擴容機制存在的。對於失敗的請求，我們也是有重試的。但是這個問題給我們帶來的影響是：
- 由於瞬時壓力到來，新啟動的實例可能一開始就會有大量請求到來，導致接口請求和建立連接之後的心跳請求混合。並且由於這些請求並沒有公平隊列排序，某些心跳請求響應過慢從而導致失敗，重新建立連接依然可能失敗。
- 有些實例可能建立的連接比較少，不能滿足並發度需求。導致很多請求其實阻塞在等待連接的過程，從而使 CPU 壓力沒有一下子變很大，所以沒有繼續觸發擴容。這樣對於擴容帶來了更大的滯後性。
其實，如果我們有辦法盡量減少或者避免連接創建失敗，那麼就能很大程度優化這個問題。即在微服務實例開始提供服務前，就將連接池中所有的連接創建好。
如何實現 Redis 連接池連接預創建
我們首先看看，是否可以藉助於官方配置，實現這個連接池。
我們查看官方文檔，發現了這樣兩個配置：
min-idle 即連接池中最少的連接數。 time-between-eviction-runs 是定時任務，檢查連接池中的連接是否滿足至少有 min-idle 的個數，同時，不超過 max-idle 那麼多個數。官方文檔中說，min-idle 只有配合 time-between-eviction-runs 都配置，才會生效。究其原因是：lettuce 的鏈接池是基於 commons-pool 實現的。連接池可以配置 min-idle，但是需要手動調用 preparePool，才會創建至少 min-idle 個數的對象：
GenericObjectPool
public void preparePool() throws Exception {
//如果配置了有效的 min-idle，則調用 ensureMinIdle 保證創建至少 min-idle 個數的對象
if (this.getMinIdle() >= 1) {
this.ensureMinIdle();
}
}那麼這個是在什麼時候調用呢？ commons-pool 有定時任務，初始延遲和定時間隔都是 time-between-eviction-runs，配置的，其內容是：
public void run() {
final ClassLoader savedClassLoader =
Thread.currentThread().getContextClassLoader();
try {
if (factoryClassLoader != null) {
// Set the class loader for the factory
final ClassLoader cl = factoryClassLoader.get();
if (cl == null) {
// The pool has been dereferenced and the class loader
// GC'd. Cancel this timer so the pool can be GC'd as
// well.
cancel();
return;
}
Thread.currentThread().setContextClassLoader(cl);
}
// Evict from the pool
try {
evict();
} catch(final Exception e) {
swallowException(e);
} catch(final OutOfMemoryError oome) {
// Log problem but give evictor thread a chance to continue
// in case error is recoverable
oome.printStackTrace(System.err);
}
// Re-create idle instances.
try {
ensureMinIdle();
} catch (final Exception e) {
swallowException(e);
}
} finally {
// Restore the previous CCL
Thread.currentThread().setContextClassLoader(savedClassLoader);
}
}可以看出，這個定時任務執行主要保證當前池內空閑對象個數不超過 max-idle，同時至少有 min-idle 個鏈接。這些都是 common-pools 自己帶的機制。但是沒有我們需要的，在連接池一創建就去初始化所有鏈接。
這就需要我們自己實現了，我們首先配置 min-idle = max-idle = max-active，這樣無論何時連接池中都有同樣最大個數的鏈接。之後，我們在連接池創建出來的地方，修改源碼，強制調用 preparePool 去初始化所有鏈接，即：
ConnectionPoolSupport
// lettuce 初始化創建連接池的時候，會調用這個方法
public static <T extends StatefulConnection<?, ?>> GenericObjectPool<T> createGenericObjectPool(
Supplier<T> connectionSupplier, GenericObjectPoolConfig<T> config, boolean wrapConnections) {
//省略其他代碼
GenericObjectPool<T> pool = new GenericObjectPool<T>(new RedisPooledObjectFactory<T>(connectionSupplier), config) {
@Override
public T borrowObject() throws Exception {
return wrapConnections ? ConnectionWrapping.wrapConnection(super.borrowObject(), poolRef.get())
: super.borrowObject();
}
@Override
public void returnObject(T obj) {
if (wrapConnections && obj instanceof HasTargetConnection) {
super.returnObject((T) ((HasTargetConnection) obj).getTargetConnection());
return;
}
super.returnObject(obj);
}
};
//創建好後，調用 preparePool
try {
pool.preparePool();
} catch (Exception e) {
throw new RedisConnectionException("prepare connection pool failed",e);
}
//省略其他代碼
}這樣，我們就可以實現初始化 Redis 的時候，在微服務真正提供服務之前，初始化所有 Redis 鏈接。由於這裡涉及源碼修改，大家目前可以通過在項目中添加同名同路徑的類，進行依賴庫源碼替換。針對這個優化，我也向 lettuce 提了 issue 以及對應的 pull request：
