Redis CPU不到20%接口为什么还是成批超时Redis CPU只有18%内存使用率不到60%。监控里没有明显慢命令连接数也没有打满。但应用每隔几分钟就会出现一批Redis超时。看到这种现象很多人的第一反应是Redis没满问题应该不在Redis。这次事故恰恰相反。Redis执行命令确实不慢真正慢的是一批体积很大的返回结果。命令执行完成后数据还要经过Redis输出缓冲区、网络和Java客户端解码应用才能拿到结果。服务端CPU不高只能证明CPU没有持续繁忙不能证明整条调用链没有排队。一、故障现场所有指标都不像Redis有问题事故发生时商品查询接口出现周期性尖刺正常P9970ms 异常P992.8s Redis客户端超时2s Redis CPU18% Redis内存57%应用日志里集中出现Redis command timed out Command timed out after 2 second(s)我们先查了Redis慢日志redis-cli-hhost-pportSLOWLOG GET20没有找到对应时间点的慢命令。再看吞吐、连接和阻塞客户端redis-cli-hhost-pportINFO stats redis-cli-hhost-pportINFO clients redis-cli-hhost-pportINFO commandstatsQPS没有明显上涨blocked_clients也接近0。于是排查一度走偏大家开始怀疑GC、线程池和网络抖动却忽略了一个关键事实SLOWLOG记录的是命令执行时间不包含把结果通过网络发送给客户端的时间。二、慢日志为空不等于Redis调用很快一次Redis调用可以粗略拆成五段客户端排队 → 请求写入网络 → Redis执行命令 → 结果通过网络返回 → 客户端读取并解码SLOWLOG主要覆盖中间的“执行命令”。如果命令只执行了3ms但返回了8MB数据网络发送、客户端读取和反序列化可能远远超过3ms。这也是为什么下面两个结论不能画等号SLOWLOG没有记录 ≠ 应用侧Redis耗时没有问题Redis官方文档明确说明慢日志的执行时间不包含客户端I/O。因此Redis超时时必须同时看两个视角服务端执行了多久应用从发出请求到拿到结果用了多久三、真正的根因一个HGETALL返回了几MB我们按超时时间点检查应用调用最终定位到一个缓存读取MapObject,ObjectsnapshotredisTemplate.opsForHash().entries(product:snapshot:tenantId);代码看起来只是一次Hash读取。但某些租户把几万条商品快照全部塞进了同一个Hash。高峰时这个Key已经增长到数十万个field单次返回结果达到数MB。问题随之出现HGETALL需要遍历整个HashRedis要为客户端准备大量返回数据大响应进入客户端输出缓冲区Java客户端读取并解码大量对象Netty事件循环被大响应占用其他请求跟着延迟于是我们看到一种很迷惑的现象Redis整体CPU不高 单条命令未必进入慢日志 但一批应用请求同时超时如果Redis是共享实例一个大Key带来的长响应还可能拖慢其他完全无关的业务。四、我会按这5组证据排查1. 先确认超时发生在哪一段不要只保留一句“Redis timeout”。至少区分获取客户端连接超时 连接Redis超时 写请求超时 等待响应超时 客户端解码耗时过长同时对齐应用侧P95/P99、Redis命令名和Key类型。2. 查SLOWLOG但不要止步于SLOWLOGredis-cli-hhost-pportSLOWLOG LEN redis-cli-hhost-pportSLOWLOG GET50redis-cli-hhost-pportCONFIG GET slowlog-log-slower-than生产环境修改阈值前要先评估权限、日志容量和变更流程不要临时随手改完就忘记恢复。3. 查命令分布和延迟事件redis-cli-hhost-pportINFO commandstats redis-cli-hhost-pportINFO latencystats redis-cli-hhost-pportLATENCY LATEST redis-cli-hhost-pportLATENCY DOCTORlatencystats等字段与Redis版本有关没有该分区时先确认实例版本。LATENCY监控默认可能没有启用需要根据业务可接受延迟设置阈值并遵循生产变更流程。4. 查客户端输出缓冲区redis-cli-hhost-pportCLIENT LIST重点关注omem客户端输出缓冲区占用 qbuf查询缓冲区占用 cmd最近执行的命令 idle连接空闲时间如果少数客户端的omem持续增大通常说明响应生成速度超过了客户端消费速度。CLIENT LIST可能包含地址、连接名等信息保存和分享时要脱敏。5. 查大Key和返回体积不要在生产高峰直接运行可能造成全量扫描的命令。可以先从业务Key规则、采样任务和只读副本入手再使用渐进式工具核实redis-cli--bigkeysredis-cli--memkeys这些工具会扫描Key空间执行前应评估实例规模、链路负载和运行窗口。五、为什么增加超时时间只是把问题藏起来把客户端超时从2秒改成5秒可能暂时减少异常日志。但等待中的请求会占用更多应用线程和连接最终把上游也拖住Redis大响应 → 客户端等待时间变长 → Tomcat线程占用变长 → 请求开始排队 → Nginx或网关继续超时超时时间应该根据业务SLA和下游能力设计而不是发生超时后不断往上加。如果问题是大Key和大响应真正的修复仍然是减少一次调用的数据量。六、最终怎么修我们没有继续提高超时而是做了四件事。1. 把一个大Hash拆分由“一个租户一个大Hash”改成按业务维度和分页拆分控制单个Key和单次返回规模。2. 不再使用HGETALL读取全量接口只返回当前页面需要的字段批量读取也设置明确上限。3. 给不同Redis操作建立独立指标至少记录命令类型 调用次数 P95/P99 超时数 返回条目数或响应字节数4. 给异常大响应设置保护当查询范围超过上限时直接分页、降级或拒绝避免一个请求拖慢整个共享客户端。修复后异常租户的单次返回从数MB下降到几十KB接口P99恢复到百毫秒以内批量超时消失。七、Redis批量超时排查清单遇到“Redis不忙但应用超时”我会按这个顺序检查对齐应用超时和Redis实例的时间线区分连接、写入、响应和客户端解码超时检查SLOWLOG阈值及最近记录检查INFO commandstats和latencystats检查LATENCY LATEST/DOCTOR检查CLIENT LIST中的输出缓冲区检查大Key、大响应和高复杂度命令检查客户端事件循环、连接池和线程栈检查网络丢包、重传和跨可用区链路修复后用真实数据规模重新压测写在最后Redis CPU不到20%不代表Redis调用一定很快。慢日志为空也不代表客户端在超时时间内一定能拿到结果。排查Redis延迟时别只盯着“命令执行了多久”还要看“结果多大、网络传了多久、客户端处理了多久”。这是「性能排障周」第2篇归入「生产环境保命清单」。如果你的同事还在用“CPU不高所以Redis没问题”下结论可以把这篇转给他。你遇到过Redis服务端不忙、应用却批量超时的情况吗最后是大Key、网络、客户端还是持久化抖动欢迎把最终证据留在留言区。系列导航上一篇《接口只慢了500ms为什么200个Tomcat线程还是被打满》下一篇《接口平均耗时只有80ms用户为什么还是觉得卡》关注我回复关键词保命获取完整「生产环境保命清单」。如需协助判断可发送脱敏后的错误、指标、命令结果和时间线。请隐藏密码、Token、IP、域名及客户数据。 Redis CPU不到20%，接口为什么还是成批超时？
Redis CPU不到20%接口为什么还是成批超时Redis CPU只有18%内存使用率不到60%。监控里没有明显慢命令连接数也没有打满。但应用每隔几分钟就会出现一批Redis超时。看到这种现象很多人的第一反应是Redis没满问题应该不在Redis。这次事故恰恰相反。Redis执行命令确实不慢真正慢的是一批体积很大的返回结果。命令执行完成后数据还要经过Redis输出缓冲区、网络和Java客户端解码应用才能拿到结果。服务端CPU不高只能证明CPU没有持续繁忙不能证明整条调用链没有排队。一、故障现场所有指标都不像Redis有问题事故发生时商品查询接口出现周期性尖刺正常P9970ms 异常P992.8s Redis客户端超时2s Redis CPU18% Redis内存57%应用日志里集中出现Redis command timed out Command timed out after 2 second(s)我们先查了Redis慢日志redis-cli-hhost-pportSLOWLOG GET20没有找到对应时间点的慢命令。再看吞吐、连接和阻塞客户端redis-cli-hhost-pportINFO stats redis-cli-hhost-pportINFO clients redis-cli-hhost-pportINFO commandstatsQPS没有明显上涨blocked_clients也接近0。于是排查一度走偏大家开始怀疑GC、线程池和网络抖动却忽略了一个关键事实SLOWLOG记录的是命令执行时间不包含把结果通过网络发送给客户端的时间。二、慢日志为空不等于Redis调用很快一次Redis调用可以粗略拆成五段客户端排队 → 请求写入网络 → Redis执行命令 → 结果通过网络返回 → 客户端读取并解码SLOWLOG主要覆盖中间的“执行命令”。如果命令只执行了3ms但返回了8MB数据网络发送、客户端读取和反序列化可能远远超过3ms。这也是为什么下面两个结论不能画等号SLOWLOG没有记录 ≠ 应用侧Redis耗时没有问题Redis官方文档明确说明慢日志的执行时间不包含客户端I/O。因此Redis超时时必须同时看两个视角服务端执行了多久应用从发出请求到拿到结果用了多久三、真正的根因一个HGETALL返回了几MB我们按超时时间点检查应用调用最终定位到一个缓存读取MapObject,ObjectsnapshotredisTemplate.opsForHash().entries(product:snapshot:tenantId);代码看起来只是一次Hash读取。但某些租户把几万条商品快照全部塞进了同一个Hash。高峰时这个Key已经增长到数十万个field单次返回结果达到数MB。问题随之出现HGETALL需要遍历整个HashRedis要为客户端准备大量返回数据大响应进入客户端输出缓冲区Java客户端读取并解码大量对象Netty事件循环被大响应占用其他请求跟着延迟于是我们看到一种很迷惑的现象Redis整体CPU不高 单条命令未必进入慢日志 但一批应用请求同时超时如果Redis是共享实例一个大Key带来的长响应还可能拖慢其他完全无关的业务。四、我会按这5组证据排查1. 先确认超时发生在哪一段不要只保留一句“Redis timeout”。至少区分获取客户端连接超时 连接Redis超时 写请求超时 等待响应超时 客户端解码耗时过长同时对齐应用侧P95/P99、Redis命令名和Key类型。2. 查SLOWLOG但不要止步于SLOWLOGredis-cli-hhost-pportSLOWLOG LEN redis-cli-hhost-pportSLOWLOG GET50redis-cli-hhost-pportCONFIG GET slowlog-log-slower-than生产环境修改阈值前要先评估权限、日志容量和变更流程不要临时随手改完就忘记恢复。3. 查命令分布和延迟事件redis-cli-hhost-pportINFO commandstats redis-cli-hhost-pportINFO latencystats redis-cli-hhost-pportLATENCY LATEST redis-cli-hhost-pportLATENCY DOCTORlatencystats等字段与Redis版本有关没有该分区时先确认实例版本。LATENCY监控默认可能没有启用需要根据业务可接受延迟设置阈值并遵循生产变更流程。4. 查客户端输出缓冲区redis-cli-hhost-pportCLIENT LIST重点关注omem客户端输出缓冲区占用 qbuf查询缓冲区占用 cmd最近执行的命令 idle连接空闲时间如果少数客户端的omem持续增大通常说明响应生成速度超过了客户端消费速度。CLIENT LIST可能包含地址、连接名等信息保存和分享时要脱敏。5. 查大Key和返回体积不要在生产高峰直接运行可能造成全量扫描的命令。可以先从业务Key规则、采样任务和只读副本入手再使用渐进式工具核实redis-cli--bigkeysredis-cli--memkeys这些工具会扫描Key空间执行前应评估实例规模、链路负载和运行窗口。五、为什么增加超时时间只是把问题藏起来把客户端超时从2秒改成5秒可能暂时减少异常日志。但等待中的请求会占用更多应用线程和连接最终把上游也拖住Redis大响应 → 客户端等待时间变长 → Tomcat线程占用变长 → 请求开始排队 → Nginx或网关继续超时超时时间应该根据业务SLA和下游能力设计而不是发生超时后不断往上加。如果问题是大Key和大响应真正的修复仍然是减少一次调用的数据量。六、最终怎么修我们没有继续提高超时而是做了四件事。1. 把一个大Hash拆分由“一个租户一个大Hash”改成按业务维度和分页拆分控制单个Key和单次返回规模。2. 不再使用HGETALL读取全量接口只返回当前页面需要的字段批量读取也设置明确上限。3. 给不同Redis操作建立独立指标至少记录命令类型 调用次数 P95/P99 超时数 返回条目数或响应字节数4. 给异常大响应设置保护当查询范围超过上限时直接分页、降级或拒绝避免一个请求拖慢整个共享客户端。修复后异常租户的单次返回从数MB下降到几十KB接口P99恢复到百毫秒以内批量超时消失。七、Redis批量超时排查清单遇到“Redis不忙但应用超时”我会按这个顺序检查对齐应用超时和Redis实例的时间线区分连接、写入、响应和客户端解码超时检查SLOWLOG阈值及最近记录检查INFO commandstats和latencystats检查LATENCY LATEST/DOCTOR检查CLIENT LIST中的输出缓冲区检查大Key、大响应和高复杂度命令检查客户端事件循环、连接池和线程栈检查网络丢包、重传和跨可用区链路修复后用真实数据规模重新压测写在最后Redis CPU不到20%不代表Redis调用一定很快。慢日志为空也不代表客户端在超时时间内一定能拿到结果。排查Redis延迟时别只盯着“命令执行了多久”还要看“结果多大、网络传了多久、客户端处理了多久”。这是「性能排障周」第2篇归入「生产环境保命清单」。如果你的同事还在用“CPU不高所以Redis没问题”下结论可以把这篇转给他。你遇到过Redis服务端不忙、应用却批量超时的情况吗最后是大Key、网络、客户端还是持久化抖动欢迎把最终证据留在留言区。系列导航上一篇《接口只慢了500ms为什么200个Tomcat线程还是被打满》下一篇《接口平均耗时只有80ms用户为什么还是觉得卡》关注我回复关键词保命获取完整「生产环境保命清单」。如需协助判断可发送脱敏后的错误、指标、命令结果和时间线。请隐藏密码、Token、IP、域名及客户数据。