问题现象与背景
昨晚我们的网关雪崩了一段时间,现象是:
1.不断有各种微服务报异常:在写 HTTP 响应的时候,连接已经关闭:
reactor.netty.http.client.PrematureCloseException: Connection prematurely closed BEFORE response
复制代码
2.同时还有请求还没读取完,连接已经关闭的异常:
org.springframework.http.converter.HttpMessageNotReadableException: I/O error while reading input message; nested exception is java.io.IOException: UT000128: Remote peer closed connection before all data could be read
复制代码
3.前端不断有请求超时的报警,504 Gateway Time-out
4.网关进程不断健康检查失败而被重启
5.重启后的网关进程,立刻请求数量激增,每个实例峰值 2000 qps,闲时每个实例 500 qps,忙时由于有扩容也能保持每个实例在 1000 qps 以内,然后健康检查接口就很长时间没有响应,导致实例不断重启
其中,1 和 2 的问题应该是应为网关不断重启,并且由于某些原因优雅关闭失败导致强制关闭,强制关闭导致连接被强制断开从而有 1 和 2 相关的异常。
我们的网关是基于 Spring Cloud Gateway 实现的,并且有自动根据 CPU 负载扩容的机制。奇怪的是在请求数量彪增的时候,CPU 利用率并没有提高很多,保持在 60% 左右,由于 CPU 负载没有达到扩容的界限,所以一直没有自动扩容。为了快速解决问题,我们手动扩容了几个网关实例,将网关单实例负载控制在了 1000 以内,暂时解决了问题。
问题分析
为了彻底解决这个问题,我们使用 JFR 分析。首先先根据已知的线索去分析:
- Spring Cloud Gateway 是基于 Spring-WebFlux 实现的异步响应式网关,http 业务线程是有限的(默认是 2 * 可以使用的 CPU 个数,我们这里是 4)。
- 网关进程不断健康检查失败,健康检查调用的是 /actuator/health 接口,这个接口一直超时。
健康检查接口超时一般有两个原因:
- 健康检查接口检查某个组件的时候,阻塞住了。例如数据库如果卡住,那么可能数据库健康检查会一直没有返回。
- http 线程池没来得及处理健康检查请求,请求就超时了。
我们可以先去看 JFR 中的定时堆栈,看是否有 http 线程卡在健康检查上面。查看出问题后的线程堆栈,重点关注那 4 个 http 线程,结果发现这 4 个线程的堆栈基本一样,都是在执行 Redis 命令:
"reactor-http-nio-1" #68 daemon prio=5 os_prio=0 cpu=70832.99ms elapsed=199.98s tid=0x0000ffffb2f8a740 nid=0x69 waiting on condition [0x0000fffe8adfc000]
java.lang.Thread.State: TIMED_WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@11.0.8/Native Method)
- parking to wait for <0x00000007d50eddf8> (a java.util.concurrent.CompletableFuture$Signaller)
at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.8/LockSupport.java:234)
at java.util.concurrent.CompletableFuture$Signaller.block(java.base@11.0.8/CompletableFuture.java:1798)
at java.util.concurrent.ForkJoinPool.managedBlock(java.base@11.0.8/ForkJoinPool.java:3128)
at java.util.concurrent.CompletableFuture.timedGet(java.base@11.0.8/CompletableFuture.java:1868)
at java.util.concurrent.CompletableFuture.get(java.base@11.0.8/CompletableFuture.java:2021)
at io.lettuce.core.protocol.AsyncCommand.await(AsyncCommand.java:83)
at io.lettuce.core.internal.Futures.awaitOrCancel(Futures.java:244)
at io.lettuce.core.FutureSyncInvocationHandler.handleInvocation(FutureSyncInvocationHandler.java:75)
at io.lettuce.core.internal.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:80)
at com.sun.proxy.$Proxy245.get(Unknown Source)
at org.springframework.data.redis.connection.lettuce.LettuceStringCommands.get(LettuceStringCommands.java:68)
at org.springframework.data.redis.connection.DefaultedRedisConnection.get(DefaultedRedisConnection.java:267)
at org.springframework.data.redis.connection.DefaultStringRedisConnection.get(DefaultStringRedisConnection.java:406)
at org.springframework.data.redis.core.DefaultValueOperations$1.inRedis(DefaultValueOperations.java:57)
at org.springframework.data.redis.core.AbstractOperations$ValueDeserializingRedisCallback.doInRedis(AbstractOperations.java:60)
at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:222)
at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:189)
at org.springframework.data.redis.core.AbstractOperations.execute(AbstractOperations.java:96)
at org.springframework.data.redis.core.DefaultValueOperations.get(DefaultValueOperations.java:53)
at com.jojotech.apigateway.filter.AccessCheckFilter.traced(AccessChec