Redis P99 升至 80ms,先查 SLOWLOG

监控出现“Redis P99 延迟升到 80ms”时,最有效的排查顺序是:先保存告警时间窗和实例信息,读取 Redis 现有配置与诊断数据,再把客户端端到端耗时和 Redis 服务端耗时对齐,最后分别检查 SLOWLOG GET、LATENCY DOCTOR 和 LATENCY HISTOGRAM。如果 Redis 内部没有对应证据,再转查网络、连接池、客户端排队和重试。

排查 Redis P99 延迟升到 80ms 时,先区分三条命令各自回答的问题:SLOWLOG 找的是具体慢命令,LATENCY DOCTOR 找的是内部延迟尖峰类别,LATENCY HISTOGRAM 补的是命令延迟分布。三者不是互斥方案;Redis 内部耗时也不能替代客户端看到的完整请求耗时。

先把 80ms 拆成服务端与客户端两段

看到 P99 告警后,先不要执行 SLOWLOG RESET 或 LATENCY RESET,也不要立即修改阈值。第一步应记录告警开始和结束时间、实例地址、节点角色、读写流量,以及监控采用的统计窗口。随后读取当前配置和已经积累的诊断数据:

redis-cli CONFIG GET slowlog-log-slower-than
redis-cli CONFIG GET slowlog-max-len
redis-cli SLOWLOG LEN
redis-cli CONFIG GET latency-monitor-threshold

这些命令都是只读的。SLOWLOG LEN 只能说明当前保留了多少条记录,不能说明 Redis 是否发生过阻塞;slowlog-log-slower-than 的单位是微秒,而 latency-monitor-threshold 的单位是毫秒。后者为 0 时表示 Latency Monitor 没有启用,而且它不能补录启用之前发生的历史尖峰。

还要先确认监控里的“Redis P99”究竟统计什么。客户端 P99 通常包含连接池等待、请求排队、网络往返、Redis 服务端执行和响应接收;SLOWLOG 只统计命令在 Redis 服务端的实际执行时间,不包含读取客户端请求、发送响应等网络 I/O。 因此,即使客户端 P99 已经达到 80ms,Redis 命令耗时仍可能远低于这个数字。

如果 Redis 命令耗时明显低于客户端 P99,应优先检查网络 RTT、连接池获取等待、客户端线程排队和重试风暴。反过来,如果客户端和服务端耗时都接近 80ms,就应继续追查具体命令;如果只有 fork、AOF 写入或过期清理等内部事件出现 80ms 尖峰,则不一定能在 SLOWLOG 中找到对应的慢命令。

比较时必须使用同一时间窗、同一实例和同一节点角色。慢日志时间戳、客户端监控时间戳和采集器时间最好统一换算成 UTC,否则“日志时间与告警时间对不上”很容易把排查方向带偏。

三组命令各查一层,不要混用结论

三种工具的职责边界如下:

工具 回答的问题 结果之后怎么走
SLOWLOG GET 哪条命令超过了配置阈值 核对命令和参数,继续查慢操作、大集合或 BigKey
LATENCY DOCTOR 哪类内部事件出现过延迟尖峰 查看对应 LATENCY HISTORY,再关联 fork、AOF、过期或淘汰
LATENCY HISTOGRAM 某类命令的延迟分布如何 判断是少量尖峰还是整体右移,再回到业务调用

SLOWLOG 是命令级证据,LATENCY DOCTOR 是事件级诊断;诊断报告提供的是汇总线索,具体命令仍然要回到慢日志或其他原始数据确认。

先看 SLOWLOG GET:

redis-cli SLOWLOG GET 20

读取记录时,优先核对慢日志 ID、Unix 时间戳、执行耗时、命令及参数、客户端地址和客户端名称。执行耗时单位是微秒。参数列表可能因版本和长度限制而截断,较新的 Redis 版本还会返回原始参数总数,可用来判断是否存在参数规模异常的批量命令,具体输出字段需要按目标版本确认。

如果现有阈值过高,可以在保存原值后临时使用以下配置:

redis-cli CONFIG SET slowlog-log-slower-than 5000
redis-cli CONFIG SET slowlog-max-len 1000
redis-cli SLOWLOG GET 20

5000 微秒等于 5 毫秒,但这只是便于抓取异常的示例值,不是通用生产标准。慢日志容量有上限,较早记录可能被覆盖;临时调小 slowlog-max-len 还可能挤掉已有证据,所以应先归档当前日志,排查结束后恢复原配置。

slowlog-log-slower-than 为 0 时,慢日志会记录所有执行时间大于零的命令,而不是关闭慢日志;这一点和 latency-monitor-threshold=0 的含义不同。版本差异、ACL 限制以及 managed Redis 对 CONFIG SET 的限制都需要在目标实例上确认。

slowlog-log-slower-than 配置过高会让 5~10ms 的命令不进入慢日志;slowlog-max-len 太小则会让日志被快速覆盖;而慢请求来自 fork、过期清理等非普通命令路径时,慢日志也可能完全为空。 因此,SLOWLOG GET 没有结果不能证明 Redis 没有发生过阻塞。

LATENCY DOCTOR 要先通过 LATENCY LATEST 找事件类别,再回到 LATENCY HISTORY 看原始时间序列:

redis-cli LATENCY LATEST
redis-cli LATENCY HISTORY command
redis-cli LATENCY GRAPH command
redis-cli LATENCY DOCTOR

上面的 command 只是事件名称示例。实际应替换成 LATENCY LATEST 返回的事件,例如 fork、aof-write、expire-cycle 或 eviction-cycle。

Latency Monitor 默认关闭,阈值使用毫秒。为了捕获约 80ms 的尖峰,临时阈值应低于 80ms,例如可以先尝试 50ms,再观察事件量是否过大:

redis-cli CONFIG SET latency-monitor-threshold 50
redis-cli LATENCY LATEST
redis-cli LATENCY DOCTOR

这个设置只用于示例。启用前要保存原值,结束后恢复;如果告警发生前监控尚未启用,修改阈值也只能捕获之后的尖峰,不能还原已经过去的现场。

不同事件代表不同方向:command 表示普通命令出现异常耗时,fast-command 表示原本应该很快的命令变慢,fork 对应创建子进程,aof-* 指向 AOF 写入或同步,expire-cycle 和 eviction-cycle 分别关联过期清理和内存淘汰压力。 LATENCY DOCTOR 会汇总尖峰次数、最坏值、发生周期和建议,但定位时仍应查看 LATENCY LATEST 和 LATENCY HISTORY。

Latency Monitor 每个事件最多保留 160 个样本,同一秒内发生多个尖峰时只保留最大值。因此它适合回答“尖峰什么时候集中出现”,不能用来计算完整请求分布或精确 P99。LATENCY DOCTOR 没有数据,常见原因是监控未启用、启用后尚未超过阈值、事件已经超出保留范围,或者本次延迟根本不属于它记录的代码路径。

最后再补 LATENCY HISTOGRAM:

redis-cli LATENCY HISTOGRAM
redis-cli LATENCY HISTOGRAM <command>

它和 SLOWLOG 的区别在于:慢日志只保留超过阈值的近期命令,Histogram 用累计桶展示命令延迟分布。由此可以判断 80ms 是少量长尾请求,还是大量命令的分布整体右移;也可以从累计计数估算分位,但桶边界不是精确的 P99,落入哪个桶只能得到一个区间。

LATENCY HISTOGRAM 的命令支持情况、过滤语法和输出字段需要按目标 Redis 版本的官方文档核对,不能写死一个适用于所有实例的版本号。若命令不支持,采集器应记录“unknown command”之类的实际错误,并降级到 SLOWLOG、LATENCY HISTORY 和客户端埋点。它同样只描述 Redis 内部命令延迟,不能替代客户端端到端 P99。

按命中证据收敛根因,再让三份证据对齐复测

如果 SLOWLOG 命中了 O(N) 命令、大集合全量读取、超大范围 LRANGE、集合聚合或疑似 Lua 脚本,下一步应检查一次处理的数据量、返回结果大小和参数规模。常见改法是使用有界分页、增量处理,或按业务需要访问部分元素,避免一次把大集合全部拉回客户端。

同一数据规模下,SET 或 DEL 突然变慢时,应怀疑 BigKey。写入大值需要分配内存,删除大值需要释放内存;如果 BigKey 同时具有过期时间,过期清理也可能放大耗时。 可以用受控扫描检查 key 大小分布:

redis-cli -h "$HOST" -p "$PORT" --bigkeys -i 0.01

这里的 0.01 是扫描间隔,用来降低扫描速度。线上扫描本身仍可能推高 QPS,因此应先在低峰或从副本验证,再把扫描结果与慢日志时间点对应,不能把一次全实例扫描当成无成本操作。

如果 LATENCY DOCTOR 命中 fork,应把尖峰时间与 RDB 或 AOF 重写时间关联,再检查主机 CPU、内存和磁盘状态;如果命中 aof-*,则把事件时间与 AOF 写入、同步时间关联。LATENCY DOCTOR 的建议只能确定排查方向,不能代替系统指标和 Redis 持久化状态。

expire-cycle 指向过期清理压力,eviction-cycle 指向内存淘汰压力。集中设置 TTL、大量 key 同时过期、BigKey 集中释放内存,都可能拉长清理周期;主动过期清理在 Redis 主线程执行时,其他请求只能排队等待。 这时应检查 TTL 分布、内存使用和淘汰情况,而不是只搜索慢命令。

如果三份 Redis 证据都没有与 80ms 对应的异常,排查重点应转到客户端。分别测量连接池获取连接耗时、请求排队耗时、服务端处理耗时和完整端到端耗时,再检查连接池上限、客户端线程池、网络 RTT 以及超时重试是否形成重试风暴。 此时 Redis 很快,80ms 很可能一直消耗在 Redis 之外。

只有读取副本的流量变慢,或故障转移后开始变慢时,还要单独检查复制状态:

redis-cli INFO replication

不要因为某一时刻主从 offset 存在差值就直接判定复制异常。更可靠的证据是主库 offset 持续增长而从库 offset 长时间不动,或者差值持续扩大;复制积压、网络丢包或从库慢命令都可能造成这种表现。

需要持续取证时,可以周期性采集三组数据。下面是一个待验证的最小 Go 模板,示例使用 github.com/redis/go-redis/v9 的通用 Do 接口;如果项目使用其他客户端库,需要按实际版本核对 API、返回类型、认证和 TLS 配置。

package main

import (
    "context"
    "encoding/json"
    "fmt"
    "log"
    "os"
    "path/filepath"
    "strings"
    "time"

    "github.com/redis/go-redis/v9"
)

type sample struct {
    ObservedAtUTC string   `json:"observed_at_utc"`
    Command       []string `json:"command"`
    Result        any      `json:"result,omitempty"`
    ResultText    string   `json:"result_text,omitempty"`
    Error         string   `json:"error,omitempty"`
}

func normalize(value any) any {
    switch v := value.(type) {
    case map[interface{}]interface{}:
        out := make(map[string]any, len(v))
        for key, item := range v {
            out[fmt.Sprint(key)] = normalize(item)
        }
        return out
    case []interface{}:
        out := make([]any, len(v))
        for i, item := range v {
            out[i] = normalize(item)
        }
        return out
    default:
        return value
    }
}

func save(dir string, at time.Time, command []string, result any, err error) {
    record := sample{
        ObservedAtUTC: at.Format(time.RFC3339Nano),
        Command:       command,
    }

    if err != nil {
        record.Error = err.Error()
    } else {
        record.Result = normalize(result)
        record.ResultText = fmt.Sprintf("%#v", result)
    }

    data, marshalErr := json.MarshalIndent(record, "", "  ")
    if marshalErr != nil {
        log.Printf("marshal %v: %v", command, marshalErr)
        return
    }

    name := fmt.Sprintf(
        "%s_%s.json",
        at.Format("20060102T150405.000000000Z"),
        strings.Join(command, "_"),
    )

    if writeErr := os.WriteFile(filepath.Join(dir, name), data, 0600); writeErr != nil {
        log.Printf("write %v: %v", command, writeErr)
    }
}

func main() {
    addr := os.Getenv("REDIS_ADDR")
    if addr == "" {
        addr = "127.0.0.1:6379"
    }

    dir := os.Getenv("OUT_DIR")
    if dir == "" {
        dir = "./redis-latency-snapshots"
    }

    interval := 10 * time.Second
    if raw := os.Getenv("INTERVAL"); raw != "" {
        parsed, err := time.ParseDuration(raw)
        if err != nil {
            log.Fatal(err)
        }
        interval = parsed
    }

    if err := os.MkdirAll(dir, 0700); err != nil {
        log.Fatal(err)
    }

    client := redis.NewClient(&redis.Options{Addr: addr})
    defer client.Close()

    probes := [][]string{
        {"CONFIG", "GET", "slowlog-log-slower-than"},
        {"CONFIG", "GET", "slowlog-max-len"},
        {"CONFIG", "GET", "latency-monitor-threshold"},
        {"SLOWLOG", "LEN"},
        {"SLOWLOG", "GET", "20"},
        {"LATENCY", "LATEST"},
        {"LATENCY", "HISTORY", "command"},
        {"LATENCY", "DOCTOR"},
        {"LATENCY", "HISTOGRAM"},
    }

    ctx := context.Background()
    ticker := time.NewTicker(interval)
    defer ticker.Stop()

    for {
        roundTime := time.Now().UTC()

        for _, probe := range probes {
            args := make([]any, len(probe))
            for i, value := range probe {
                args[i] = value
            }

            result, err := client.Do(ctx, args...).Result()
            save(dir, roundTime, probe, result, err)
        }

        <-ticker.C
    }
}

模板不会清空慢日志或延迟历史;LATENCY HISTOGRAM 不受支持时,错误也会写入对应快照。生产环境还应根据 LATENCY LATEST 返回的事件名,补充采集 fork、AOF、过期和淘汰等事件的 LATENCY HISTORY。采集结果属于解析后的结构化数据,如果取证要求保留 CLI 原文或协议字节,还应同步归档 redis-cli 的原始 stdout。慢日志参数可能包含业务数据,输出目录和文件权限需要按敏感数据处理。

修复后,一次低延迟请求不足以判断问题已经解决。应使用相同的命令集合、数据规模、并发量和运行时长复测,并同时对照客户端 P99、SLOWLOG 最大执行耗时、LATENCY 事件最坏值和 Histogram 估算分位。临时修改的慢日志阈值、日志容量和延迟监控阈值都要在验证后恢复。

排查和复测按以下顺序执行:

  1. 保存告警的 UTC 时间窗、实例、节点角色、请求类型和客户端 P99 统计口径。
  2. 读取现有配置,导出 SLOWLOG GET、LATENCY LATEST、LATENCY DOCTOR、LATENCY HISTORY 和支持时的 LATENCY HISTOGRAM,期间不执行重置命令。
  3. 命令证据走慢查询、大集合或 BigKey 分支;事件证据走 fork、AOF、过期和淘汰分支;三份 Redis 证据都没有与 80ms 对应的异常时,转查网络、连接池和客户端排队。
  4. 修复后使用相同负载复测,并让客户端 P99、服务端慢日志、事件最坏值和直方图分位互相印证。
  5. 归档每轮原始结果与配置变更记录,恢复临时参数,再决定下一轮监控阈值。
© 版权声明
THE END
喜欢就支持一下吧
点赞0 分享
评论 抢沙发

请登录后发表评论

    暂无评论内容