这个 Redis 连接池的新监控方式针不戳~我再加一点佐料

2021-08-12 11:00 https://my.oschina.net/u/3747772/blog/5178362 干货满满张哈希次阅读条评论

Lettuce 是一个 Redis 连接池，和 Jedis 不一样的是，Lettuce 是主要基于 Netty 以及 ProjectReactor 实现的异步连接池。由于基于 ProjectReactor，所以可以直接用于 spring-webflux 的异步项目，当然，也提供了同步接口。

在我们的微服务项目中，使用了 Spring Boot 以及 Spring Cloud。并且使用了 spring-data-redis 作为连接 Redis 的库。并且连接池使用的是 Lettuce。同时，我们线上的 JDK 是 OpenJDK 11 LTS 版本，并且每个进程都打开了 JFR 记录。关于 JFR，可以参考这个系列：JFR 全解

在 Lettuce 6.1 之后，Lettuce 也引入了基于 JFR 的监控事件。参考：events.flight-recorder

1. Redis 连接相关事件：

ConnectEvent：当尝试与 Redis 建立连接之前，就会发出这个事件。
ConnectedEvent：连接建立的时候会发出的事件，包含建立连接的远程 IP 与端口以及使用的 Redis URI 等信息，对应 Netty 其实就是 ChannelHandler 中的 channelActive 回调一开始就会发出的事件。
ConnectionActivatedEvent：在完成 Redis 连接一系列初始化操作之后（例如 SSL 握手，发送 PING 心跳命令等等），这个连接可以用于执行 Redis 命令时发出的事件。
ConnectionDeactivatedEvent：在没有任何正在处理的命令并且 isOpen() 是 false 的情况下，连接就不是活跃的了，准备要被关闭。这个时候就会发出这个事件。
DisconnectedEvent：连接真正关闭或者重置时，会发出这个事件。
ReconnectAttemptEvent：Lettuce 中的 Redis 连接会被维护为长连接，当连接丢失，会自动重连，需要重连的时候，会发出这个事件。
ReconnectFailedEvent：当重连并且失败的时候的时候，会发出这个事件。

2. Redis 集群相关事件：

AskRedirectionEvent：针对 Redis slot 处于迁移状态时会返回 ASK，这时候会发出这个事件。
MovedRedirectionEvent：针对 Redis slot 不在当前节点上时会返回 MOVED，这时候会发出这个事件。
TopologyRefreshEvent：如果启用了集群拓补刷新的定时任务，在查询集群拓补的时候，就会发出这个事件。但是，这个需要在配置中开启定时检查集群拓补的任务，参考 cluster-topology-refresh
ClusterTopologyChangedEvent：当 Lettuce 发现 Redis 集群拓补发生变化的时候，就会发出这个事件。

3. Redis 命令相关事件：

CommandLatencyEvent：Lettuce 会统计每个命令的响应时间，并定时发出这个事件。这个也是需要手动配置开启的，后面会提到如何开启。
CommandStartedEvent：开始执行某一指令的时候会发出这个事件。
CommandSucceededEvent：指令执行成功的时候会发出这个事件。
CommandFailedEvent：指令执行失败的时候会发出这个事件。

Lettuce 的监控是基于事件分发与监听机制的设计，其核心接口是 EventBus:

EventBus.java

public interface EventBus {

    // 获取 Flux，通过 Flux 订阅，可以允许多个订阅者

    Flux<Event> get();

    // 发布事件

    void publish(Event event);

}

其默认实现为 DefaultEventBus，

public class DefaultEventBus implements EventBus {

    private final DirectProcessor<Event> bus;

    private final FluxSink<Event> sink;

    private final Scheduler scheduler;

    private final EventRecorder recorder = EventRecorder.getInstance();



    public DefaultEventBus(Scheduler scheduler) {

        this.bus = DirectProcessor.create();

        this.sink = bus.sink();

        this.scheduler = scheduler;

    }



    @Override

    public Flux<Event> get() {

        //如果消费不过来直接丢弃

        return bus.onBackpressureDrop().publishOn(scheduler);

    }



    @Override

    public void publish(Event event) {

        //调用 recorder 记录

        recorder.record(event);

        //调用 recorder 记录之后，再发布事件

        sink.next(event);

    }

}

在默认实现中，我们发现发布一个事件首先要调用 recorder 记录，之后再放入 FluxSink 中进行事件发布。目前 recorder 有实际作用的实现即基于 JFR 的 JfrEventRecorder.查看源码：

JfrEventRecorder

public void record(Event event) {

    LettuceAssert.notNull(event, "Event must not be null");

    //使用 Event 创建对应的 JFR Event，之后直接 commit，即提交这个 JFR 事件到 JVM 的 JFR 记录中

    jdk.jfr.Event jfrEvent = createEvent(event);

    if (jfrEvent != null) {

        jfrEvent.commit();

    }

}



private jdk.jfr.Event createEvent(Event event) {

    try {

        //获取构造器，如果构造器是 Object 的构造器，代表没有找到这个 Event 对应的 JFR Event 的构造器

        Constructor<?> constructor = getEventConstructor(event);

        if (constructor.getDeclaringClass() == Object.class) {

            return null;

        }

        //使用构造器创建 JFR Event

        return (jdk.jfr.Event) constructor.newInstance(event);

    } catch (ReflectiveOperationException e) {

        throw new IllegalStateException(e);

    }

}



//Event 对应的 JFR Event 构造器缓存

private final Map<Class<?>, Constructor<?>> constructorMap = new HashMap<>();



private Constructor<?> getEventConstructor(Event event) throws NoSuchMethodException {

    Constructor<?> constructor;

    //简而言之，就是查看缓存 Map 中是否存在这个 class 对应的 JFR Event 构造器，有则返回，没有则尝试发现

    synchronized (constructorMap) {

        constructor = constructorMap.get(event.getClass());

    }

    if (constructor == null) {

    

        //这个发现的方式比较粗暴，直接寻找与当前 Event 的同包路径下的以 Jfr 开头，后面跟着当前 Event 名称的类是否存在

        //如果存在就获取他的第一个构造器（无参构造器），不存在就返回 Object 的构造器

        String jfrClassName = event.getClass().getPackage().getName() + ".Jfr" + event.getClass().getSimpleName();



        Class<?> eventClass = LettuceClassUtils.findClass(jfrClassName);



        if (eventClass == null) {

            constructor = Object.class.getConstructor();

        } else {

            constructor = eventClass.getDeclaredConstructors()[0];

            constructor.setAccessible(true);

        }



        synchronized (constructorMap) {

            constructorMap.put(event.getClass(), constructor);

        }

    }



    return constructor;

}

发现这块代码并不是很好，每次读都要获取锁，所以我做了点修改并提了一个 Pull Request：reformat getEventConstructor for JfrEventRecorder not to synchronize for each read

由此我们可以知道，一个 Event 是否有对应的 JFR Event 通过查看是否有同路径的以 Jfr 开头后面跟着自己名字的类即可。目前可以发现：

io.lettuce.core.event.connection 包：
- ConnectedEvent -> JfrConnectedEvent
- ConnectEvent -> JfrConnectedEvent
- ConnectionActivatedEvent -> JfrConnectionActivatedEvent
- ConnectionCreatedEvent -> JfrConnectionCreatedEvent
- ConnectionDeactivatedEvent -> JfrConnectionDeactivatedEvent
- DisconnectedEvent -> JfrDisconnectedEvent
- ReconnectAttemptEvent -> JfrReconnectAttemptEvent
- ReconnectFailedEvent -> JfrReconnectFailedEvent
io.lettuce.core.cluster.event 包：
- AskRedirectionEvent -> JfrAskRedirectionEvent
- ClusterTopologyChangedEvent -> JfrClusterTopologyChangedEvent
- MovedRedirectionEvent -> JfrMovedRedirectionEvent
- AskRedirectionEvent -> JfrTopologyRefreshEvent
io.lettuce.core.event.command 包：
- CommandStartedEvent -> 无
- CommandSucceededEvent -> 无
- CommandFailedEvent -> 无
io.lettuce.core.event.metrics 包：、
- CommandLatencyEvent -> 无

我们可以看到，当前针对指令，并没有 JFR 监控，但是对于我们来说，指令监控反而是最重要的。我们考虑针对指令相关事件添加 JFR 对应事件

如果对 io.lettuce.core.event.command 包下的指令事件生成对应的 JFR，那么这个事件数量有点太多了（我们一个应用实例可能每秒执行好几十万个 Redis 指令）。所以我们倾向于针对 CommandLatencyEvent 添加 JFR 事件。

CommandLatencyEvent 包含一个 Map：

private Map<CommandLatencyId, CommandMetrics> latencies;

其中 CommandLatencyId 包含 Redis 连接信息，以及执行的命令。CommandMetrics 即时间统计，包含：

收到 Redis 服务器响应的时间指标，通过这个判断是否是 Redis 服务器响应慢。
处理完 Redis 服务器响应的时间指标，可能由于应用实例过忙导致响应一直没有处理完，通过这个与收到 Redis 服务器响应的时间指标对比判断应用处理花的时间。

这两个指标都包含如下信息：

最短时间
最长时间
百分位时间，默认是前 50%，前 90%，前 95%，前 99%，前 99.9%，对应源码：MicrometerOptions: public static final double[] DEFAULT_TARGET_PERCENTILES = new double[] { 0.50, 0.90, 0.95, 0.99, 0.999 };

我们想要实现针对每个不同 Redis 服务器每个命令都能通过 JFR 查看一段时间内响应时间指标的统计，可以这样实现：

package io.lettuce.core.event.metrics;



import jdk.jfr.Category;

import jdk.jfr.Event;

import jdk.jfr.Label;

import jdk.jfr.StackTrace;



@Category({ "Lettuce", "Command Events" })

@Label("Command Latency Trigger")

@StackTrace(false)

public class JfrCommandLatencyEvent extends Event {

    private final int size;



    public JfrCommandLatencyEvent(CommandLatencyEvent commandLatencyEvent) {

        this.size = commandLatencyEvent.getLatencies().size();

        commandLatencyEvent.getLatencies().forEach((commandLatencyId, commandMetrics) -> {

            JfrCommandLatency jfrCommandLatency = new JfrCommandLatency(commandLatencyId, commandMetrics);

            jfrCommandLatency.commit();

        });

    }

}

package io.lettuce.core.event.metrics;



import io.lettuce.core.metrics.CommandLatencyId;

import io.lettuce.core.metrics.CommandMetrics;

import jdk.jfr.Category;

import jdk.jfr.Event;

import jdk.jfr.Label;

import jdk.jfr.StackTrace;



import java.util.concurrent.TimeUnit;



@Category({ "Lettuce", "Command Events" })

@Label("Command Latency")

@StackTrace(false)

public class JfrCommandLatency extends Event {

    private final String remoteAddress;

    private final String commandType;

    private final long count;

    private final TimeUnit timeUnit;

    private final long firstResponseMin;

    private final long firstResponseMax;

    private final String firstResponsePercentiles;

    private final long completionResponseMin;

    private final long completionResponseMax;

    private final String completionResponsePercentiles;



    public JfrCommandLatency(CommandLatencyId commandLatencyId, CommandMetrics commandMetrics) {

        this.remoteAddress = commandLatencyId.remoteAddress().toString();

        this.commandType = commandLatencyId.commandType().toString();

        this.count = commandMetrics.getCount();

        this.timeUnit = commandMetrics.getTimeUnit();

        this.firstResponseMin = commandMetrics.getFirstResponse().getMin();

        this.firstResponseMax = commandMetrics.getFirstResponse().getMax();

        this.firstResponsePercentiles = commandMetrics.getFirstResponse().getPercentiles().toString();

        this.completionResponseMin = commandMetrics.getCompletion().getMin();

        this.completionResponseMax = commandMetrics.getCompletion().getMax();

        this.completionResponsePercentiles = commandMetrics.getCompletion().getPercentiles().toString();

    }

}

这样，我们就可以这样分析这些事件：

首先在事件浏览器中，选择 Lettuce -> Command Events -> Command Latency，右键使用事件创建新页：

在创建的事件页中，按照 commandType 分组，并且将感兴趣的指标显示到图表中：

针对这些修改，我也向社区提了一个 Pull Request：fix #1820 add JFR Event for Command Latency

在 Spring Boot 中（即增加了 spring-boot-starter-redis 依赖），我们需要手动打开 CommandLatencyEvent 的采集：

@Configuration(proxyBeanMethods = false)

@Import({LettuceConfiguration.class})

//需要强制在 RedisAutoConfiguration 进行自动装载

@AutoConfigureBefore(RedisAutoConfiguration.class)

public class LettuceAutoConfiguration {

}

import io.lettuce.core.event.DefaultEventPublisherOptions;

import io.lettuce.core.metrics.DefaultCommandLatencyCollector;

import io.lettuce.core.metrics.DefaultCommandLatencyCollectorOptions;

import io.lettuce.core.resource.DefaultClientResources;

import org.springframework.context.annotation.Bean;

import org.springframework.context.annotation.Configuration;



import java.time.Duration;



@Configuration(proxyBeanMethods = false)

public class LettuceConfiguration {

    /**

     * 每 10s 采集一次命令统计

     * @return

     */

    @Bean

    public DefaultClientResources getDefaultClientResources() {

        DefaultClientResources build = DefaultClientResources.builder()

                .commandLatencyRecorder(

                        new DefaultCommandLatencyCollector(

                                //开启 CommandLatency 事件采集，并且配置每次采集后都清空数据

                                DefaultCommandLatencyCollectorOptions.builder().enable().resetLatenciesAfterEvent(true).build()

                        )

                )

                .commandLatencyPublisherOptions(

                        //每 10s 采集一次命令统计

                        DefaultEventPublisherOptions.builder().eventEmitInterval(Duration.ofSeconds(10)).build()

                ).build();

        return build;

    }

}