原文: 一次Redis访问超时的“捉虫”之旅

力是相互的，成长与痛苦也是相互的。

01-引言

最近在对一个老项目使用的docker镜像版本升级过程中碰到一个奇怪的问题，发现项目升级到高版本镜像后，访问Redis会出现很多超时错误，而降回之前的镜像版本后问题也随之消失。经过排查，最终定位问题元凶是一个涉及到Lettuce、Redis、Netty等多块内容的代码bug。
在问题解决过程中也对相关组件的工作方式有了更深一步的理解。以下就对“捉虫”过程中的问题分析和排查过程做一个详细的介绍。

03-问题现象

为了固定问题场景，我们进行了一番条件测试，发现了一些端倪：

• 低版本镜像上RedisTemplete和缓存框架访问Redis集群均正常。
• 高版本镜像上RedisTemplete访问Redis集群正常，缓存框架访问Redis集群超时。项目启动一段时间后框架访问恢复正常。
• 低版本和高版本镜像中RedisTemplete和缓存框架访问Redis单机均正常

根据以上现象不难推断出，问题应似乎出现在缓存框架访问Redis集群的机制上。结合项目启动一段时间后会恢复正常的特点，猜测应该和缓存预热流程有关。

04-排查过程

复现case

查阅代码后发现自研的缓存框架没有通过Spring访问Redis，而是直接使用了Sping底层的Redis客户端——Lettuce。

排查至此，我们发现缓冲区的数据积压很可能就是造成反查请求超时的原因，明白了这一点后，我们开始思考：

• 连接缓冲区中的数据应该由谁来消费？
• 每个连接的作用是什么？
• 为什么只有一个连接出现了数据积压情况？
• 为什么积压情况只在高版本的镜像中出现？
• 为什么通过Spring访问Redis就不会出现超时问题？

深度分析

要回答以上问题，首先要了解Lettuce的工作原理，重点是其底层是如何访问Redis集群的。

根据官网介绍，Lettuce 底层基于 Netty 的NIO模型实现，只用有限的线程支持更多的 Redis 连接，在高负载情况下能更有效地利用系统资源。

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线程上。

针对这种应用场景Lettuce官网上也有专门提醒：https://lettuce.io/core/release/reference/index.html

• 即不要在Pub/Sub的回调函数中执行阻塞操作。
  

解决方案

原因定位后，解决方案也呼之欲出。有两种方法：

增加io线程

异步化

比较优雅的方式是不要在nio线程中执行阻塞操作，即将处理Pub/Sub消息的过程异步化，最好放到独立的线程中执行，以尽早释放Netty的EventLoop资源。我们熟悉的spring-data-redis框架就是这么做的。

• Spring-data-redis的做法是每次收到消息时都新启动新线程处理。
  

思考

尽管问题已经解决，但之前还有几个遗留的疑问没有解答。经过一番研究，我们也找到了答案。

为什么低版本镜像没问题？

在之前的分析中，我们提到了因为 EventLoop 线程数量过少导致线程阻塞。高版本的实例中 EventLoop 线程数量为 3，那么低版本的情况呢？通过Arthas 查看，发现低版本 Lettuce 的 EventLoop 数量是 13，远远超过了高版本的数量。这表示在低版本环境中，Pub/Sub 连接和其他连接会注册到不同的 EventLoop 上，即使 Pub/Sub 处理线程被阻塞，也不会影响到其他连接读写事件的处理。

为什么低版本的镜像会创建更多的 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上，避免了冲突。

05-总结

本文从实际工作中遇到的一个Redis访问超时问题出发，探究背后Spring、Lettuce和Netty的工作原理，并利用Arthas等调试工具，分析了EventLoop线程对连接处理的重要性，以及在处理Pub/Sub事件时避免阻塞操作的必要性。通过观察不同版本环境下的行为差异，加深了对JDK版本和程序环境适配的理解，为今后排查类似问题积累了宝贵经验。