Redis的耗时统计全面解析|如何使用与源码剖析

前言

最近在写lua的脚本，想测一下lua的脚本执行耗时，就统计了一下慢日志。除此之外，想统计一下Redis的网络耗时，这时就需要统计命令的发送与响应的耗时了(逻辑耗时+网络耗时)。这时就需要借助Lettuce提供的耗时统计功能了。

本篇文章主要教大家如何使用这两个工具以及内置统计的原理；

功能介绍

目前根据Wiki上的介绍，Lettuce提供了两种统计方式：

• 内置统计(since version 3.4）

  基于HdrHistogram 和 LatencyUtils开发的命令耗时统计功能；提供统计每个命令的耗时，以及直方图数据；

• Micrometer(since version 6.1)

  基于micrometer-core开发的耗时统计；

安装依赖

内置统计

<dependency>
    <groupId>org.latencyutils</groupId>
    <artifactId>LatencyUtils</artifactId>
    <version>2.0.3</version>
</dependency>

Micrometer

<dependency>
    <groupId>io.micrometer</groupId>
    <artifactId>micrometer-core</artifactId>
    <version>1.10.5</version><!-- e.g. micrometer.version==1.6.0 -->
</dependency>

如何使用

内置统计

基于订阅发布模型统计数据；

主要参数介绍：

统计参数

DefaultCommandLatencyCollectorOptions implements CommandLatencyCollectorOptions {
    // 时间单位
    public static final TimeUnit DEFAULT_TARGET_UNIT = TimeUnit.MICROSECONDS;
    // 直方图分布，占比50%的时间，占比90%的时间，占比95%的时间，占比99%的时间，占比99.9%的时间，
    public static final double[] DEFAULT_TARGET_PERCENTILES = new double[] { 50.0, 90.0, 95.0, 99.0, 99.9 };
    // 发送完Event事件后，统计数据是否清空，重新统计
    public static final boolean DEFAULT_RESET_LATENCIES_AFTER_EVENT = true;
    // 是否记录本地IP地址
    public static final boolean DEFAULT_LOCAL_DISTINCTION = false;
    // 是否开启统计
    public static final boolean DEFAULT_ENABLED = true;
}

命令发布者参数

public class DefaultEventPublisherOptions implements EventPublisherOptions {
    // 发布时间，单位秒，默认10s
    public static final long DEFAULT_EMIT_INTERVAL = 10;
}

使用：

// 构造客户端参数
private ClientResources createClientResources() {
    // 构造记录器的参数
    CommandLatencyCollectorOptions collectorOptions = CommandLatencyCollectorOptions.builder().enable().build();
    // 构造记录器
    DefaultCommandLatencyCollector defaultCommandLatencyCollector = new DefaultCommandLatencyCollector(collectorOptions);
    // 构造发布者发送事件 每秒发送一次
    DefaultEventPublisherOptions build = DefaultEventPublisherOptions.builder().eventEmitInterval(Duration.ofSeconds(1)).build();
    // 构造客户端配置
    return DefaultClientResources.builder()
        .ioThreadPoolSize(redisClientThreadNum)
        .computationThreadPoolSize(computationThreadPoolSize)
        .commandLatencyRecorder(defaultCommandLatencyCollector)
        .commandLatencyPublisherOptions(build)
        .build();
}
​
// 连接
public void connect() {
    this.redisClient = RedisClient.create(createClientResources(), redisURI);
    this.redisClient.setOptions(createClientOptions());
    // 连接状态信息
    connection = redisClient.connect();
    this.redisSyncCommands = connection.sync();
    // 对内封装的接口
    StatefulRedisConnectionImpl statefulRedisConnection = (StatefulRedisConnectionImpl) connection;
    this.redisAsyncCommand = new RedisAsyncCommandsImpl<String, String>(connection,  statefulRedisConnection.getCodec());
    this.redisReactiveCommands = connection.reactive();
    // 获取客户端的EventBus
    EventBus eventBus = redisClient.getResources().eventBus();
    
    // 订阅者
    eventBus.get()
        .filter(redisEvent -> redisEvent instanceof CommandLatencyEvent)
        .cast(CommandLatencyEvent.class)
        .subscribe(e -> {
            System.out.println(e.getLatencies());
        });
}

输出解析：

local:本地地址 -> 远端Redis服务器地址；

commandType=命令类型；

count=统计数量；

timeUnit=时间类型；

firstResponse=命令耗时[min=最小时间, max=最大时间, 直方图分布={50.0=占比50%的时间, 90.0=占比90%的时间, 95.0=占比95%的时间, 99.0=占比99%的时间, 99.9=占比99.9%的时间}]；

firstResponse=是命令响应 - 发送时间；

completion=命令完成耗时[min=最短完成时间, max=最大完成时间, percentiles={50.0=788529, 90.0=830472, 95.0=830472, 99.0=830472, 99.9=830472}]；

completion=命令解码处理完 - 发送时间；

{[local:any -> 5ixp.cn/81.68.168.134:6379, commandType=EVALSHA]=[count=1595, timeUnit=MICROSECONDS, firstResponse=[min=784334, max=830472, percentiles={50.0=788529, 90.0=830472, 95.0=830472, 99.0=830472, 99.9=830472}], completion=[min=784334, max=830472, percentiles={50.0=788529, 90.0=830472, 95.0=830472, 99.0=830472, 99.9=830472}]]}

Micrometer

不是和内置统计一样基于订阅发布模式的，我们需要自行定义线程池或者自行定义事件发布者去处理统计信息；

// 构造客户端参数
private ClientResources createClientResourcesWithMicrometer() {
    // 简单的统计对象（从它获取统计数据）
    SimpleMeterRegistry simpleMeterRegistry = new SimpleMeterRegistry();
    // 统计参数
    MicrometerOptions options = MicrometerOptions.builder().enable().histogram(true).build();
    // 定义统计记录器
    MicrometerCommandLatencyRecorder micrometerCommandLatencyRecorder = new MicrometerCommandLatencyRecorder(simpleMeterRegistry, options);
    // 定义线程池，用于每秒获取统计数据
    Executors.newScheduledThreadPool(1).scheduleAtFixedRate(() -> {
        System.out.println(simpleMeterRegistry.getMetersAsString());
    }, 1, 1, TimeUnit.SECONDS);
​
    // 无需设置发布者，设置了也没用
    return DefaultClientResources.builder()
        .ioThreadPoolSize(redisClientThreadNum)
        .computationThreadPoolSize(computationThreadPoolSize)
        .commandLatencyRecorder(micrometerCommandLatencyRecorder)
        .build();
}
​
// 连接
public void connect() {
    this.redisClient = RedisClient.create(createClientResourcesWithMicrometer(), redisURI);
    this.redisClient.setOptions(createClientOptions());
    // 连接状态信息
    connection = redisClient.connect();
    this.redisSyncCommands = connection.sync();
    // 对内封装的接口
    StatefulRedisConnectionImpl statefulRedisConnection = (StatefulRedisConnectionImpl) connection;
    this.redisAsyncCommand = new RedisAsyncCommandsImpl<String, String>(connection,  statefulRedisConnection.getCodec());
    this.redisReactiveCommands = connection.reactive();
}

输出参数

此处参数不作详解，输出已经相对直观

lettuce.command.completion(TIMER)[command='HELLO', local='local:any', remote='5ixp.cn/81.68.168.134:6379']; count=1.0, total_time=0.1838794 seconds, max=0.1838794 seconds
# 50%占比
lettuce.command.completion.percentile(GAUGE)[command='HELLO', local='local:any', phi='0.5', remote='5ixp.cn/81.68.168.134:6379']; value=0.176160768 seconds
# 99%占比
lettuce.command.completion.percentile(GAUGE)[command='HELLO', local='local:any', phi='0.99', remote='5ixp.cn/81.68.168.134:6379']; value=0.176160768 seconds

源码剖析

本文仅对内置统计进行源码剖析，其耗时统计均在Netty数据传输层进行统计；

主要分为三个阶段

0. 发送命令的时候在Netty发送数据的时候记录发送时间；
1. 接收命令结果的时候在Netty收到数据的时候记录响应时间，以及解码等操作后记录命令的完成时间；
2. 定期通过EventBus将统计的记录发送出去；并根据配置，判定统计数据发送后是否需要清空之前的统计记录；

第一阶段

我们在发送的时候，CommandHandler内置了一个stack，用户保存发送的命令缓存。如果我们客户端没有开启统计，则直接加入stack中。若开启了统计，则会封装成LatencyMeteredCommand包装类型，增加了发送时间，响应时间，完成时间等属性，用于统计；

第二阶段

命令在接收的时候会先记录当前的响应时间，若开启了数据统计，当完成数据解码后会再记录完成时间；其内部通过直方图对象，记录当前命令的响应时间等数据；后期直接通过直方图对象获取统计结果。

我们的记录器中有一个Map，Map的key是由（本地地址，远端的地址，命令类型）生成的Key，参数是封装了的直方图对象。

第三阶段

我们默认开启了一个定时器，定时器会每隔X秒去获取当前统计的Map数据，若开启了统计后重置（DEFAULT_RESET_LATENCIES_AFTER_EVENT=true）则会将Map清空；目的是统计X秒内的耗时情况。通过EventBus，将事件抛出，订阅者会捕获事件并打印耗时数据；

相关网站

lettuce.io/

hdrhistogram.org/

github.com/lettuce-io/…