Redis明明很慢，为什么SLOWLOG一条都没有？

一、慢日志为空，不代表 Redis 调用没有问题

假设某个接口出现了这样的现象：

应用监控显示，一次 Redis 调用耗时接近 200 毫秒；进入 Redis 查看 SLOWLOG，却找不到对应记录。

有人判断是网络问题，有人怀疑监控不准，还有人直接把客户端超时调大。

在修改配置之前，应该先弄清楚：

应用记录的“Redis 调用耗时”，和 Redis 慢日志记录的“命令执行耗时”，不是同一个指标。

Redis 官方文档明确说明，SLOWLOG 记录的是命令实际执行所花费的时间，不包含与客户端通信、发送响应等 I/O 时间。因此，不能直接拿应用侧的一次调用耗时，与慢日志中的执行时间画等号。

1. 一次调用的时间花在哪里

为了便于分析，可以将一次调用近似拆成下面几个阶段。实际客户端可能存在异步处理或阶段重叠，具体计时边界仍需以埋点位置为准。

graph LR
    A["客户端准备与排队"] --> B["请求传输"]
    B --> C["服务端等待"]
    C --> D["命令执行"]
    D --> E["响应传输"]
    E --> F["客户端结果处理"]

SLOWLOG 主要观察其中的“命令执行”阶段，而不是整条链路。由此可以推导：即使一条命令真正执行得很快，只要它在执行前等待，或者执行后迟迟没有被客户端处理完成，应用侧仍然会感到慢。

举一个用于说明计时边界的假设场景：

某次请求在执行前等待了 199 毫秒，实际执行 GET 只用了 0.1 毫秒。如果慢日志阈值是 10 毫秒，这条 GET 不会因为前面的等待而自动成为一条 199.1 毫秒的慢日志。

所以，排查方向不应该只是：

哪条命令执行得慢？

还应该包括：

命令开始执行之前，以及执行完成之后，时间花到了哪里？

2. 不要用两个 P99 相减计算网络耗时

还有一种容易出现的误判：

应用侧 Redis 调用 P99 是 200 毫秒，服务端命令执行 P99 是 1 毫秒，于是认为网络 P99 是 199 毫秒。

这个计算不成立。

两个 P99 未必来自同一批请求，更不一定对应同一个请求。即使每次调用都能拆成多个阶段，各阶段的 P99 也不能直接相加或相减。

需要定位单次异常时，应尽量追踪同一次调用；需要分析整体趋势时，则应对齐实例、命令类型、时间窗口和统计口径。

二、先确认不是“看错了监控”

还没开始分析网络、CPU 和线程池之前，先核对目标实例与采集配置。

下面的命令使用 Bash。先明确目标地址，后续命令在同一个终端中执行：

# 修改为需要排查的目标实例。
REDIS_HOST="127.0.0.1"
REDIS_PORT="6379"

rcli() {
  redis-cli -h "$REDIS_HOST" -p "$REDIS_PORT" "$@"
}

启用了 ACL 或 TLS 的环境，需要在函数内补齐相应连接参数。密码可以通过 REDISCLI_AUTH 环境变量提供，避免直接写进命令参数。

1. 先看配置，再解释结果

date -Is

rcli INFO server
rcli CONFIG GET slowlog-log-slower-than
rcli CONFIG GET slowlog-max-len
rcli CONFIG GET latency-monitor-threshold
rcli SLOWLOG GET 20

这里有三个容易混淆的配置：

另外，slowlog-log-slower-than 为负数时关闭慢日志，为 0 时记录每条命令。它与 latency-monitor-threshold 的单位、零值含义都不同。

没有数据之前，先确认监控是否启用、阈值是否合适、记录是否仍在保留窗口内。

这里说的内部延迟事件监控，也不要与 INFO latencystats 提供的命令延迟分布混为一谈，两者是不同的观测机制。

2. 核对业务请求实际访问的节点

排障时，建议把应用记录的远端地址作为核对依据，而不是只凭配置文件中的入口地址。

尤其是存在代理、主从切换或分片的环境，需要确认自己查看的节点，确实处理过异常请求。

可以将这一点作为排障约定：

任何一份慢日志、客户端指标和服务端指标，都标明对应实例与采集时间。

另外，不要为了“让数据干净一点”，一进入生产实例就执行 SLOWLOG RESET。清空操作会删除现有记录，可能同时清掉故障证据。

三、建立基线：是整个路径慢，还是只有业务调用慢

接下来，从应用所在主机或尽可能相同的网络环境中，观察轻量请求的往返延迟：

rcli --latency-history -i 5

redis-cli 的延迟模式通过持续发送 PING 采样；--latency-history 按时间段展示结果，这里的 -i 5 将历史统计窗口设为 5 秒。观察结束后使用 Ctrl+C 退出。

随后，在 Redis 所在主机上，对同一个目标实例做一次对应观察。

可以用下面这张表缩小范围。它是排查优先级，不是直接定责规则：

这里必须保留一个边界：

小响应的 PING 正常，只能说明这条探测连接上的轻量请求表现正常。

它没有经过业务客户端的连接获取、任务队列和结果处理，也不代表业务大响应具有相同的表现。因此，不能仅凭 PING 正常，就排除 Redis 调用链路中的其他问题。这是根据探测方式与业务调用路径差异作出的判断。

四、四类容易被慢日志漏掉的延迟

1. 每条命令都不慢，但请求排队很严重

一个常见思维误区是：

没有慢命令，就说明服务端不忙。

对于 Redis 常规命令的主要执行路径，命令处理具有串行执行的特点。一条命令执行时，其他请求可能需要等待。等待并不要求前面一定存在一条“特别慢”的命令，也可能是大量普通命令连续占用了处理能力。

用一个简化容量模型理解：

假设平均每条命令的执行阶段耗时 40 微秒，每秒需要处理 25,000 条命令，那么仅这些执行阶段，就需要累计 1 秒的处理时间。

每条命令都远低于 10 毫秒的慢日志阈值，但这个模型已经没有剩余的串行处理时间容纳额外流量和其他工作。

这不是 Redis 的实际性能上限，只是说明：

单次执行很快，与整体容量充足，是两回事。

如何寻找证据

查看：

rcli INFO commandstats
rcli INFO clients

对同一个命令类型，在相同实例上间隔一段时间采集两次，可以计算：

• 区间调用量：Δcalls。
• 区间平均执行耗时：Δusec / Δcalls。

INFO commandstats 中的 calls、usec 和 usec_per_call 是命令执行统计，不是客户端完整往返耗时；平均值也不能替代尾延迟分析。

把区间调用量、请求突发和主线程资源情况放到同一时间轴上，比盯着累计平均值更容易发现变化。

同时注意：blocked_clients 指向等待 BLPOP 等阻塞调用的客户端数量，不是所有排队等待执行的请求数量。它为零，不能证明没有执行前等待。

对应的优化思路，是先减少无意义的重复调用、限制突发请求与批量规模，再评估是否需要分散负载，而不是仅仅继续增加客户端并发。

2. Redis 已经返回，Java 客户端却还没处理完

排查 Java 应用时，不要把所有 Redis 超时都解释成“服务端执行超时”。

Lettuce 官方文档明确提醒：阻塞 EventLoop，例如在异步回调或响应式链路中执行阻塞操作，可能导致客户端无法正常推进命令处理。

例如，一段逻辑在 Redis 异步回调中同步调用其他服务，或者执行耗时的结果处理，就值得重点检查。

这时应分开观察两个问题：

请求有没有及时交给客户端发送？响应到达之后，有没有及时完成处理？

不要默认所有问题都来自连接池

Lettuce 的连接设计允许多个线程共享，连接池并不是所有场景都必须使用的组件。只有实际采用连接池借还的调用路径，才应重点分析连接获取等待；共享连接路径则需要关注命令排队和事件循环。

因此，“把 Redis 连接池从 16 调到 128”不应该成为默认动作。

建议先核实：

实际调用是否需要借连接，等待发生在哪里，连接是否长时间被占用，以及业务回调是否阻塞了客户端处理线程。

利用首响应与完成时间区分方向

Lettuce 的观测能力区分首响应延迟与完成延迟。在 Micrometer 集成中，对应的计时器包括：

lettuce.command.firstresponse 和 lettuce.command.completion。

据此可以形成两个待验证的方向：

首响应与完成时间一起变慢时，优先检查发送、等待与服务端处理路径；首响应变化不大，但完成时间明显变长时，优先检查响应规模、传输和客户端结果处理。

这只是定位线索，不是单凭两个指标就能确定根因。客户端内部计时也不应直接当成“纯网络时间”。

对于确实耗时或阻塞的后续处理，可以考虑使用异步回调将其转移到合适的执行器，避免阻塞事件循环；Lettuce 官方异步 API 文档也明确提示了这一点。

转移线程之后，仍然需要为任务积压设置边界，否则只是把等待换了一个位置。

3. 命令执行很快，但响应太大，或者客户端消费不及时

服务端完成数据读取，并不等于客户端已经收到并处理完全部结果。SLOWLOG 不包含发送响应的完整耗时，因此返回阶段的问题可能无法在慢日志里直接体现。

这时可以按需、低频查看客户端状态：

rcli CLIENT LIST TYPE normal

CLIENT LIST 的复杂度与连接数量有关，不适合在连接规模很大的实例上进行高频全量轮询。重点可以关注以下字段：

这些字段描述的是 Redis 侧的连接缓冲状态。其中，omem 是内存占用，不应直接当作尚未发送的业务数据字节数。

如果某些连接的输出缓冲持续增长，可以据此提出假设：响应生产速度超过了后续传输或消费速度。接着再结合响应大小、连接归属和客户端处理情况验证，而不是立即认定“网络带宽不足”。

还有两个判断边界：

cmd 表示连接最近执行的命令，不能凭这一项就认定它制造了全部积压；omem 为零，也不足以证明客户端已经处理完成，因为这是服务端缓冲状态，而不是端到端完成状态。

对应的优化，应优先落在业务数据形态上：减少不必要的返回内容，控制单次批量规模，并检查是否存在异常大的结果集。

4. 进程暂时无法推进请求，而不是某条命令特别慢

Redis 不只执行业务命令，还会与操作系统、持久化和后台工作发生交互。

例如，RDB 后台保存和 AOF 重写涉及的 fork，本身就可能造成延迟；它发生在主线程上的一段系统操作中，不能简单理解为某条 GET 或 SET 的业务逻辑突然变复杂。

此时，应该补充观察内部延迟事件：

rcli LATENCY LATEST
rcli LATENCY DOCTOR
rcli LATENCY HISTORY fork

前提是相应监控已经启用，并且覆盖了故障时间窗口。若 latency-monitor-threshold 为 0，没有事件记录可能只是监控没有开启。

可以按照变更流程临时选择合适阈值，例如将 5 毫秒作为一次排障观察值，但它不是适用于所有业务的统一推荐。记录原配置，观察结束后按原值恢复。

Redis 的延迟事件能够区分命令、fork、AOF 写入、过期处理、淘汰处理等路径；具体可见事件以版本和实际触发情况为准。

同时查看：

rcli INFO stats | grep -E 'latest_fork_usec|total_forks'
rcli INFO persistence

latest_fork_usec 是最近一次 fork 的耗时，单位为微秒。它不是时间戳，所以看到一个较大的值，并不能证明这次 fork 恰好发生在当前故障窗口内。还需要结合事件时间或其他记录。

容器场景还要检查 CPU 配额

主机整体 CPU 看起来空闲，也不能直接证明容器里的 Redis 拥有足够的执行时间。

在 cgroup v2 环境下，应检查 Redis 实际所属 cgroup 的 cpu.max，以及 cpu.stat 中限流相关计数在故障窗口内的变化。还要留意祖先 cgroup 的限制，不能只看当前目录的计数就排除上层限制。

这类问题再次说明：

服务端没有记录到慢命令，并不等于服务端进程一直能够及时运行。

五、用隔离实验理解“请求慢，但命令不慢”

下面设计一个最小实验：

启动一个没有业务数据的 Redis 容器，暂停容器，在暂停期间发送 PING，随后恢复容器。

Docker 的 pause 会暂停指定容器中的进程，在 Linux 上使用相应的 cgroup 冻结机制。

这样，请求会等待进程恢复，但并不是 PING 的命令逻辑执行了一秒。

仅在本地隔离环境中运行，不要对生产容器使用暂停操作。

实验要求 Linux、Bash、Docker、redis-cli 和 timeout，并确保本机 16379 端口空闲。脚本只创建临时容器，不挂载业务数据目录；关闭持久化也仅针对这个实验实例。

#!/usr/bin/env bash
set -euo pipefail

# 避免实验客户端继承其他 Redis 实例的认证信息。
unset REDISCLI_AUTH

name="redis-latency-lab-$$"
port=16379

docker run -d --rm \
  --name "$name" \
  -p "127.0.0.1:${port}:6379" \
  redis:7.4 \
  redis-server --save "" --appendonly no >/dev/null

cleanup() {
  docker unpause "$name" >/dev/null 2>&1 || true
  docker rm -f "$name" >/dev/null 2>&1 || true
}
trap cleanup EXIT

rcli_lab() {
  timeout 5s redis-cli -h 127.0.0.1 -p "$port" "$@"
}

# 等待实验实例就绪；最终检查失败时终止脚本。
for _ in {1..50}; do
  if [[ "$(rcli_lab PING 2>/dev/null || true)" == "PONG" ]]; then
    break
  fi
  sleep 0.1
done

[[ "$(rcli_lab PING)" == "PONG" ]]

rcli_lab CONFIG SET slowlog-log-slower-than 10000
rcli_lab SLOWLOG RESET

docker pause "$name" >/dev/null

# 恢复计时与客户端请求在宿主机上执行。
(
  sleep 1
  docker unpause "$name" >/dev/null
) &
resume_pid=$!

time rcli_lab PING

wait "$resume_pid"
rcli_lab SLOWLOG GET 10

预期观察什么

在资源正常的实验环境中，PING 的墙钟耗时预计接近暂停时长，但慢日志不应因此出现一条“执行了一秒”的 PING。

环境自身的调度或其他抖动，仍可能产生额外记录。因此，观察重点不是要求所有机器上的慢日志必须绝对为空，而是：

客户端等待的那一秒，没有理由全部被归入 PING 的命令执行时间。

这个实验只是人为构造“请求等待进程恢复”的场景，不是在模拟所有线上根因。

线上遇到类似现象，仍然需要分别寻找调度、资源限制、客户端处理或网络路径的证据。

六、优化要跟着证据走，而不是跟着异常名称走

“Redis 超时”只是应用观察到的结果，不是根因分类。

可以按已经收集到的证据选择最小改动：

其中，持久化调整需要格外谨慎。

RDB、AOF 及其同步策略对应不同的数据持久性与性能取舍。不能为了让延迟曲线好看，就直接关闭生产持久化，却不评估数据恢复要求。(Redis)

另外，也不要把 MONITOR 当作常驻、无代价的诊断工具。Redis 官方文档提醒，它会带来明显的性能开销，应在确有需要时谨慎使用。(Redis)

验证时不要只比较两个平均值

建议把验证条件写清楚：

使用相近的请求速率、命令组成和响应规模，覆盖之前出现问题的时间窗口，同时检查调用延迟、错误率与吞吐量。

否则，“平均延迟下降”可能只是请求减少了，或者更多请求更早失败了，并不能证明问题已经解决。

对于本文讨论的问题，最终需要回答的是：

原来消耗时间的那个阶段，是否真的缩短了？

而不是：

调完配置以后，监控暂时有没有报警？

七、总结

排查 Redis 延迟时，最重要的不是一次执行多少条诊断命令，而是清楚每个指标测量的范围。

SLOWLOG 观察命令执行，客户端指标观察各自定义的调用阶段，应用埋点则可能覆盖更长的业务路径。只有把这些计时边界对齐，才能正确解释它们之间的差异。

当应用明显变慢、慢日志却没有记录时，不要急着认定是网络，也不要直接扩大连接池或延长超时。

先确认目标实例与监控配置，再区分客户端等待、服务端排队、实际执行、响应传输和结果处理，最后针对有证据的阶段进行修改。

慢日志为空，不是排查结束的信号，而是提醒我们：真正消耗时间的地方，可能不在命令执行阶段。