Pengzna's blog 👋

Nov 10, 2023

开源 Metric 框架调研与 IoTDB Metric 系统性能优化

DropWizard-Metric 和 MicroMeter 项目是 IoTDB Metric 系统的两大 baseline 之一。目前 IoTDB 在启动时分别提供基于 DropWizard-Metric 和 MicroMeter 实现的监控系统供用户选择。

本文基于 DropWizard-Metric 和 MicroMeter 的系统实现,对比二者实现性能优劣,期望能整合实现出 IoTDB 内部的最优监控系统,对于用户屏蔽算法库选择的参数,探究 IoTDB Metric 性能优化的可能。

1. 系统设计

  • DropWizard

DropWizard 组件类型不复杂,核心组件类图如下。后文会对其一一解析。

image-20231115143242599

  • Micrometer

在 Micrometer 中,所有监控指标都继承名为Meter的接口。Micrometer 有一组包含各种监控系统实现的模块,其中的每一种实现被称为registry

  1. Micrometer提供了与供应商无关的接口,包括 timers(计时器)gauges(量规)counters(计数器)distribution summaries(分布式摘要)long task timers(长任务定时器)。它具有维度数据模型,当与维度监视系统结合使用时,可以高效地访问特定的命名度量,并能够跨维度深入研究。
  2. 可以看到,Micrometer 的核心组件、概念等与 DropWizard 类似。但是 Micrometer 组件非常丰富(提供了很多实现),因此类图过于复杂,此处不作赘述,后文将展开分析。

1.1. 核心组件

1.1.1. MetricsRegistry / MeterRegistry

DropWizard

维护所有 Metric 的集合,在 DropWizard 中表现为 MetricSet

核心是使用了 private final ConcurrentMap<String, Metric> metrics 维护所有的 Metric,key 是 metric 的 tag 或者 name

  1. 提供了 MetricRegistryListener,目的是为了在子 registry 增加注册 metric 时,通知父 registry,同步添加到 registry 的 ConcurrentHashMap

特别设计:所有类型的 metric 共同放在一个 map 里。在 get 具体类型的 map 时,用到了 klass 进行类型判断,同时使用 MetricFilter 封装 name 匹配操作

  1. 提供对下面所有 Metric 的增删改查接口;类似 IoTDB 的 MetricService

  2. 提供了一些 Util 内部类,比如 MetricBuilder、MetricFilter,用来满足面向对象设计,与性能优化关系不大,暂时按下不表。

  3. 通常,每个应用程序只需要一个 MetricRegistry 实例,但如果想在特定报告组中组织指标,则可以选择使用更多实例。

Micrometer

Meter 是收集应用的一系列指标的接口。Meter 是由 MeterRegistry 创建的。每个支持的监控系统都必须实现MeterRegistry。

Micrometer 中包含一个 SimpleMeterRegistry,它在内存中维护每个 meter 的最新值,并且不将数据导出到任何地方。这是 Micrometer 最简单的注册表形式。

但是,在大多数情况下,Micrometer 有专门为各种监控系统设计的 MeterRegistry:如对于 Promethus 来说,它是 PromethusMeterRegistry

image-20231115143317005

甚至,我们可以自行继承 MeterRegistry 接口,定制我们需要的 Registry。定制主要出于以下几点考虑:

  1. 重写创建指标组件(Gauge 等)的方法,对于不同的监控场景,自定义创建我们需要的指标组件类型。
  2. 与 Reporter 集成。这样启动 Registry 的同时自动 report,用户无需再特地使用 Report,符合面向对象行为和状态结合的思想。
    1. 对 IoTDB 意义不大。因为 IoTDB 本来就是单独启动 Reporter 的,并且 IoTDB 的 Reporter 和 Registry 解耦。

Micrometer 还提供一种 CompositeMeterRegistry ,允许添加多个注册表。 它提供了一种将应用程序指标同时发布到各种受支持的监控系统的解决方案。

IoTDB 原本用的是 globalRegistry(本质上是一个CompositeMeterRegistry),里面套用 SimpleMeterRegistry。实际上可以认为 IoTDB 用的就是 SimpleMeterRegistry

image-20231115181326889

但是由于 globalRegistry 本质上是 CompositeMeterRegistry,它创建具体的指标项时都是创建 CompositeXXX,CompositeXXX 在具体 api 调用时存在额外的调用开销。

image-20231115181336375

咨询 IoTDB Metric 系统的负责大佬 hy 后,得知 IoTDB 使用 CompositeRegistry 的初衷是保留后续为不同 MetricSet 分配不同 Registry 的可能,以提高并发度。

对于这个问题,考虑到 Registry 的功能仅作为 create 具体的指标项,create 动作本身不具有较高的并发,因此认为可以只有一个 Registry。而将不同 MetricSet 进行存储维度上的不同分配可以通过对 Map 进行更细划分实现。

image-20231115181345900

因此,考虑将 IoTDB 的 MetricRegistry 简化成 SimpleRegistry,减少每次记录指标时多出来的函数调用开销。

此外,也可以考虑直接删除对 Micrometer Registry 的依赖(需要重写 JMX Reporter),因为 IoTDB 已经有一套 metrics 的增删改查和命名系统,与 Registry 的功能重复。删掉 Registry 后能对每个 metric 都避免重复的存储动作,节省一倍内存。代码可读性、可维护性也更好。

  • 最终采用此种方案,详细实施可见后文

1.1.2. Gauges

DropWizard

DropWizard 中的 gauge 的默认实现使用:DefaultSettableGauge

MetricBuilder<Gauge> GAUGES = new MetricBuilder<Gauge>() {
@Override
public Gauge newMetric() {
return new DefaultSettableGauge<>();
}

@Override
public boolean isInstance(Metric metric) {
return Gauge.class.isInstance(metric);
}
};

其他类型的 gauge 主要需要关注 CachedGauge,它缓存了 Gauge 中的值,并设置了过期时间。只有当值过期时,才会 reload 值。

其他的 Gauge 基本都是存取某个对象计算值的方法引用,其效率取决于具体的getValue()方法。

image-20231115181356236

Micrometer

种类比较多,主要用到的是 DefaultGaugeCompositeGauge

image-20231115181423309

Micrometer 的 gauge 不是将值的计算委托给具体的对象,而是将获取具体对象和计算值的方法解耦。如此,gauge 寄存的值不局限于某个对象的某个方法,对象和方法可以解耦,增强了可拓展性。

image-20231115181433511

至于性能上,由于 Micrometer 没有提供缓存版 gauge,因此在涉及读密集且重计算的场景时会有性能问题,预期不如 Dropwizard。考虑在 IoTDB 实现时加一层缓存进行优化。

1.1.3. Rate

DropWizard

相当于 Meter,用于度量事件响应的平均速率,它表示的是应用程序整个运行生命周期内的总速率(总请求响应量/处理请求的总毫秒数,即每秒请求数)。

除此之外,Meter 还提供了1分钟、5分钟以及15分钟的动态平均响应速率。

其实现借助了 MovingAverage

Micrometer

没有找到 Rate 语义的实现。

1.1.4. Counter

Counter 是一个常规计数器,用于对某项指标值进行累加或者递减操作。

DropWizard

Counter 本质是一个 java.util.concurrent.atomic.LongAdder,在多线程同时更新计数器的场景下,当并发量较大时,LongAdder 比 AtomicLong 具有更高的吞吐量,当然空间资源消耗也更大一些。

Micrometer

Micrometer 提供了更多种类的 Counter,基本功能都类似 CumulativeCounter,其他 Counter 的主要区别是拓展了一些和监控系统相关的功能,具体使用哪种与 Registry 有关。IoTDB 目前使用的 SimpleMeterRegistry 使 用 CumulativeCounter

image-20231115181503300

其与 DropWizard 的实现大同小异,**唯一区别是前者使用 DoubleAdder,后者使用 LongAdder**。但是前者最终接口是 long,因此涉及一些转化开销,double 本身的运算开销也较大。因此 DropWizard 性能更好。

考虑使用 LongAdder 实现 Counter。

1.1.5. Histogram / DistributionSummary

DropWizard

Histogram 反应的是数据流中的值的分布情况。包含最小值、最大值、平均值、中位数、p75、p90、p95、p98、p99以及p999数据分布情况。

节选自参考资料:

传统 Histogram 计算分位数的方法是先对整个数据集进行排序,然后取排序后的数据集中特定位置的值(比如p99就是取倒序1%位置的值)。这种方式适合于小数据集或者批处理系统,不适用于要求高吞吐量、低延时的服务。

但这样方式保留全部数据后 sort 的方式明显对内存和运算不友好。因此 Dropwizard 使用了另外的随机性算法。

对于数据量较大,系统对吞吐量、时延要求较大的场景,我们可以采用抽样的方式获取数据。(大意是通过保证概率相等的情况下,仅保留一定量的数据)

上述这种通过动态地抽取程序运行过程中的能够代表系统真实运行情况的一小部分数据来实现对整个系统运行指标的近似度量,这种方法叫做**蓄水池算法(reservoir sampling)**。

DropWizard 中有三种 reservoir,分别简单介绍下:

  1. UniformReservoir

内部为DEFAULT_SIZE = 1028的一个数组

超过大小了则随机丢弃或者不加入:

@Override
public void update(long value) {
final long c = count.incrementAndGet();
if (c <= values.length()) {
values.set((int) c - 1, value);
} else {
final long r = ThreadLocalRandom.current().nextLong(c);
if (r < values.length()) {
values.set((int) r, value);
}
}
}

来源于这篇论文:**Vitter’s R**

  1. SlidingWindowReservoir

保留最近的 N 个值,N 可以在构造函数指定

简单的滑动窗口逻辑,可以理解为用一个 ring buffer 来存储数据

@Override
public synchronized void update(long value) {
measurements[(int) (count++ % measurements.length)] = value;
}
  1. SlidingTimeWindowReservoir

保留最近 N 秒的数据,N 可以在构造函数指定

用时间而不是长度来作为滑动窗口的 window size

@Override
public void update(long value) {
if (count.incrementAndGet() % TRIM_THRESHOLD == 0) {
trim();
}
measurements.put(getTick(), value);
}

缺点是如果瞬间流量很大,该数据结构内存不可控(因为短时间内存入大量数据,且这些数据都在 window 内,短期内不会被丢弃),因此还提供了SlidingTimeWindowArrayReservoir这个替代的基础结构。

  1. ExponentiallyDecayingReservoir

MetericRegistry::histogram默认创建为该类型,内部为DEFAULT_SIZE = 1028的一个跳表

MetricBuilder<Histogram> HISTOGRAMS = new MetricBuilder<Histogram>() {
@Override
public Histogram newMetric() {
return new Histogram(new ExponentiallyDecayingReservoir());
}

@Override
public boolean isInstance(Metric metric) {
return Histogram.class.isInstance(metric);
}
};

它基于指数级别的抽样算法,根据更新时间与开始时间的差值转化为权重值,权重越大数据被保留的几率越大。

/**
* Adds an old value with a fixed timestamp to the reservoir.
*
* @param value the value to be added
* @param timestamp the epoch timestamp of {@code value} in seconds
*/
public void update(long value, long timestamp) {
rescaleIfNeeded();
lockForRegularUsage();
try {
final double itemWeight = weight(timestamp - startTime);
final WeightedSample sample = new WeightedSample(value, itemWeight);
final double priority = itemWeight / ThreadLocalRandom.current().nextDouble();

final long newCount = count.incrementAndGet();
if (newCount <= size || values.isEmpty()) {
values.put(priority, sample);
} else {
Double first = values.firstKey();
if (first < priority && values.putIfAbsent(priority, sample) == null) {
// ensure we always remove an item
while (values.remove(first) == null) {
first = values.firstKey();
}
}
}
} finally {
unlockForRegularUsage();
}
}

具体来说,ExponentiallyDecayingReservoir 会定期执行重定标(rescale)操作,以清理旧数据并降低数据的权重,从而达到淘汰数据的目的。

Rescale 的大致过程是:基于指数衰减公式 exp(-alpha * (startTime - oldStartTime))计算缩放因子,如果缩放因子等于零,说明时间差距太大,直接清空所有的样本数据;否则,遍历所有样本数据,根据缩放因子将每个样本的权重进行缩放,然后将缩放后的样本数据重新插入到数据结构中。

来源于这篇论文:**forward-decaying priority reservoir**

Micrometer

Micrometer 拥有 Histogram 类,然而 IoTDB 使用的是 Micrometer 的 DistributionSummary。

  1. Histogram 和 DistributionSummary 有什么功能区别?

实际代码可以看出:Histogram 在 Micrometer 中是作为一种基础组件,而不是一种监控指标。DistributionSummary 集成了 Histogram

image-20231115181523661

因此使用 DistributionSummary 即可。

  1. DistributionSummary 是怎么实现的?

根据官网我们知道:DistributionSummary 跟 Timer 的实现结构几乎完全一样,只不过记录的不是 time unit 的值。因此可以参考本文 1.2.5 节。

值得一提的是,Micrometer 的实现借助了 HdrHistogram 这款开源 histogram 库,后文会详细介绍。

HdrHistogram

HdrHistogram 是一款高性能、高精度 histogram 库。在 Micrometer 的 Histogram 中使用了 HdrHistogram 作为 baseline。

1. Micrometer 是怎么使用 HdrHistogram 的?

Micrometer 的 Histogram 分为 Abstract 基类和实现类。基类实现了写路径、淘汰旧数据等基本逻辑;实现类实现了读、记录新数据等 api。

  • 实现类:实际上就是 wrap 了 HdrHistogram 的 DoubleHistogram,在读路径中用到,作为暴露给外界的结果变量使用。

image-20231115181543798

  • 基类:有一个 ringBuffer,ringBuffer 的每一项都是一个 Histogram。写路径更新 ringBuffer(下一节将详细描述), 有一个函数在 takeSnapshot 时把 ringBuffer[currentBucket] 的值 copy 给实现类的 intervalHistogram(见上图),并做后续处理。
2. Micrometer 是如何结合 HdrHistogram 实现淘汰旧数据的?
  • 首先,Micrometer 用一个 ringBuffer 来存储数据。ringBuffer 的每一项就是一个 HdrHistogram(org.HdrHistogram.DoubleRecorder
  • 当导出 Snapshot 的时候,用到的是 currrentBucket 指针指向的 buffer。

image-20231115181608771

  • Micrometer 每次插入数据的时候,会往 ringBuffer 中的所有 buffer 插入数据(后文会解释「为什么要向所有的 buffer 插入数据」)

image-20231115181619688

  • Micrometer 在每次插入新数据前,会调用 rotate() 方法。

image-20231115181630199

  • rotate() 方法实现了淘汰旧数据。逻辑如下:

  • 如果上一次淘汰数据到现在的累积时间超过了阈值(该阈值可以通过 config 设置,即 IoTDB metric core 代码里设置的 expiry,默认 1 分钟),那么即实行淘汰策略:reset(清空) currrentBucket 指向的 buffer,并将 buffer 指针( currrentBucket )后移。

  • 之后新数据到来时,Micrometer 会向 ringBuffer 中的所有 buffer 插入新数据。但由于某些 buffer 已经被清空过了,因此它们就会只保存后面插入的新数据

  • 由于 Micrometer 真正用到的 histogram 是 currrentBucket 指针指向的 buffer,而每次 rotate 会将 currrentBucket 指针后移,因此相当于不断给予保存新数据 buffer 更高的权重。

  • 综上,如此就巧妙的达到了淘汰旧数据的目标。可以看出:相比于 DropWizard 每次淘汰旧数据时对跳表的复杂操作,Micrometer 的 rotate 开销不大,再配合 HdrHistogram 本身静态分桶的高写入速度(后文会提到),Micrometer 就实现了比 DropWizard 更好的(写)性能。

image-20231115181650099

  • 可优化点思考:从前面分析可以看到,Micrometer 在每次写入数据时,对 ringBuffer 的所有 bucket 都进行了写入操作。那么是否可以通过缩小 ringBuffer 的 size,从而减少写 bucket 次数,来提高 Micrometer Histogram 的写入效率?需要研究下 ringBuffer.length 的设置原理。
    • ringBuffer.length 默认设置为 3。根据上文,只要保证 ringBuffer.length 大于 1 既能保证淘汰旧数据的目的。因此考虑将 ringBuffer.length 设为 2(PR: https://github.com/apache/iotdb/pull/11500)
3. HdrHistogram 的设计思路和算法有哪些?

不同于前文提到 DropWizard 使用的随机性算法实现(淘汰旧数据),HdrHistogram 使用的是确定性算法

确定性算法本质上就是静态分桶,有点类似压缩存储的思想。用容器将所有遇到的数据全部保存起来实际上不需要将每个值都存下来,但结果也不是精确解。以达到 Histogram 所需要的计算分位数等功能。但 HdrHistogram 不是一个数字一个桶,而是一个区间一个桶。该区间的范围可以是线性增长,也可指数增长。通过一个区间分一个桶的方式, 就能通过牺牲一小部分精度,从而达到减小空间占用,并且数据大致准确的结果。

image-20231115181702444

4. HdrHistogram 具体是如何分割区间的?

前面提到,HdrHistogram 不是一个数字一个桶,而是一个区间一个桶。该区间的范围可以是线性增长,也可指数增长。现在假设有值域为 [0..R] 的区间

  • 对于线性分桶:也就是对于 0..R 如果用 B 分隔, 那么总共可以分隔 R/B 个格子,数组的size也是 R/B
  • 对于指数分桶,也就是基于指数分隔(2 的幂次),第一个桶有 2^0 个数,第二个桶有 2^1 个数… 第 n 个桶有 2^(n-1) 个数。

举个例子,比如 10w 个数字:

采用线性的分桶方法,假设每个 bucket 可以表示100个值,那么需要 1000 个 buckets, : [1..100][101..200]...[99,901..100,000]

采用指数的分桶方式,只需要 17 个 buckets, [2^K..(2^(K+1)-1)] e.g. [1..1][2..3][4..7]...[65,536..131,071]

这里 HdrHistogram 用了一个 trick:

对于分隔 buckets,HdrHistogram 同时采用了线性和指数,HdrHistogram 内部有2个 index,bucketsIdxsubBucketIndex. 前者是指数的,后者是线性的。可以根据业务精度需求控制后面的线性的大小。

image-20231115181715521

首先,所谓「分桶」就是一个 long 数组。数组的每一项就是一个桶,其意义是:统计某个区间内数据出现的次数。分桶策略决定了数组的每一项统计的区间范围是多少。

image-20231115181730237

具体来说,HdrHistogram 的分桶策略是指数和线性结合

HdrHistogram 先将需要统计的总区间通过 2 的幂次指数分成 n 个桶(如果区间长度为 l,即保证 2^(n-1) >= l),此时标识这些桶的 index 就叫 bucketIndex。而每个桶又分为 subBucketCount 个子桶(subBucketCount 是可间接配置的),这些子桶的下标就叫做 subBucketIndex

image-20231115181756401

举个例子,每个桶有 subBucketCount 个子桶,这里假设为 2048 ,那么第 1 个桶可以以 2^0 的精度表示 2^0 * 0 ~ 2^0 * 2048,即第 1 个桶可以覆盖区间 [0, 2048],且每个子桶可以覆盖 1 个值(精度是 2^0 = 1)。

这里就有一个「桶重叠」(bucket overlap) 的问题。首先我们给出结论:

  • 第 0 个桶以 2^0 = 1 的精度覆盖 0…2047,使用所有 2048 个子桶
  • 第 1 个桶以 2^1 = 2 的精度,理论上能覆盖 0… 4095,但仅使用顶部 1024 个子桶,实际上覆盖 2048..4095
  • 第 2 个桶以 2^2 = 4 的精度,理论上能覆盖 0… 8191,但仅使用顶部 1024 个子桶,实际上覆盖 4096..8191

为什么 Bucket 0 是唯一使用 2048 个子桶的,而其余桶都只使用 1024 个子桶呢?

  • 因为它们的下半部分与前面所有的存储桶重叠并且已经被覆盖:
    • 举个例子,第 k 个桶可以以 2^k 精度表示 2048 个子桶,覆盖区间为 0 * 2^k 到 2048 * 2^k
    • 但是第 k 个桶的中点:1024 * 2^k = 2048 * 2^(k-1) = 第 k-1 个存储桶的末尾,因此我们将使用前一个存储桶(第 k-1 个桶)来存储第 k 个桶起点 ~ 第 k 个桶中点的值,因为它具有更好的精度(即子桶存储的区间范围更小)

那么当一个数据被插入,实际计算其下标时,就是结合上述分桶原理,计算它所在的桶(bucketIndex)和子桶(subBucketIndex),二者经过一些简单组合运算后得到最终下标,可以参考代码:

image-20231115181812492

这样分桶的好处是:

  • 如果纯线性分桶,那么显然空间占用过大;如果纯指数分桶,又会有精度的问题。二者结合,可以较好的解决线性分桶空间占用的问题,一定程度上优化指数分桶精度的问题。整个分桶思想有点类似压缩存储,将所有数据保存起来,但是不保存具体的值。在舍弃一点精度的情况下省下大量内存。
  • 前文提到,subBucketCount 是可配置的。因此我们可以根据业务精度需求,控制线性分桶的精度大小,比较灵活。(线性分桶数越大,精度越大,所占内存越大)
    • 这也就是 Histogram 构造函数第二个参数的含义:它与 subBucketCount 有关。
      • 该参数与 subBucketCount 的转换逻辑如下

      • static int numberOfSubBuckets(final int numberOfSignificantValueDigits) {
            final long largestValueWithSingleUnitResolution = 2 * (long) Math.pow(10, numberOfSignificantValueDigits);
        
            // We need to maintain power-of-two subBucketCount (for clean direct indexing) that is large enough to
            // provide unit resolution to at least largestValueWithSingleUnitResolution. So figure out
            // largestValueWithSingleUnitResolution's nearest power-of-two (rounded up), and use that:
            int subBucketCountMagnitude = (int) Math.ceil(Math.log(largestValueWithSingleUnitResolution)/Math.log(2));
            int subBucketCount = (int) Math.pow(2, subBucketCountMagnitude);
            return subBucketCount;
        }
        

        - 该参数值域为 0-5,分别对应 `subBucketCount` 为:
        - ```Plain
        0 - 2
        1 - 32
        2 - 256
        3 - 2048
        4 - 32768
        5 - 262144
      • 该参数 IoTDB metric core 里默认配置的是 1(值域为 0 - 5,数字越大,subBucketCount 越大),最终会导致 subBucketCount 为 32

    • image-20231115181825941
5. HdrHistogram 的 resize 机制

当然以上都有个缺点,需要一个可预估的最大值(可以理解为 HdrHistogram 统计区间的最大值)。如果有超过最大值的数字(即数据大小超过了 HdrHistogram 的统计区间)

  1. 如果没有设置 autoResize,将抛出异常,存入失败。
  2. 如果设置了 autoResize,将 resize 区间(重新设置区间范围并重新分桶)
  3. 默认 autoSize 为 true

  • autoResize 是 Histogram 类里面的一个可设置参数
image-20231115182017944
6. HdrHistogram 如何确定统计区间的上下界?

答案:通过构造函数设定。

可以清晰的看到 Histogram 类的构造函数参数含义

image-20231115182041701

但 Micrometer(IoTDB)中不是直接调用该构造函数,跟进发现调用的构造函数是:

image-20231115182051030

其中,highestToLowestValueRationumberOfSignificantValueDigits 共同确定了 hdrHistogram 的上下界。跟进发现最终上下界为 [1, 127]

image-20231115182059931

  • 可优化点思考:从前面分析可以看到,当数据超过 hdrHistogram 范围时,会发生 resize,该操作有时间开销。目前的上下界 [1, 127] 显然范围有点小了,在大值数据场景下显然要 resize,甚至多次 resize。我们是否可以对每一个 timer/histogram 的使用场景预估数据区间,为每一个 timer/histogram 定制数据上下界,尽量避免 resize 操作。
7. HdrHistogram 和 DropWizard 优劣分析
  • 写入速度:Hdr 远优于 DropWizard
    • 正是因为 HdrHistogram 是静态分桶实现,所以写入友好(不需要淘汰旧数据),在 record 性能测试中比 DropWizard 表现要好。
    • HdrHistogram 底层是数组,而 DropWizard 底层是跳表,数组肯定比跳表写入快。
    • DropWizard 默认设置是每隔一段时间要 rescale 一下,而 rescale 是要锁写的。
  • 读取速度:二者差不多
    • 因为都是给定了分位数,相当于给定数组下标/跳表 key 了,直接读取基本都是 O(1)
  • 空间占用:需要具体分析。因为 HdrHistogram 可以通过指数分桶减少空间占用,而 DropWizard 的空间占用也和用户指定的容器大小有关,所以直观上不太好说谁空间占用更好,需要结合具体场景分析。

1.1.6. Timer

DropWizard

Timer 相当于 Meter + Histogram(默认使用 ExponentiallyDecayingReservoir)。可以统计接口请求速率和响应时长。会度量服务的响应速率,同时也会统计服务响应时长的分布情况。

可以说,Timer 能兼容 Meter + Histogram 的所有接口。

因此 Timer 底层的 update 主要也就是更新 Histogram 和 Meter。

Micrometer

Timer 用于度量短时间内的事件时延和响应频率。所有的 Timer 实现都记录了事件响应总耗时和事件总数。Timer 不支持负数,此外如果使用它来记录大批量、长时延事件的话,容易导致指标值数据越界(超过Long.MAX_VALUE)。

同样,Micrometer 为每种监控系统设计了不同的 Timer,主要用的是 CumulativeTimer

image-20231115182117259

Micrometer 的 Timer 相当于 Histogram + 自己实现的计时器(用 AtomicLong 累计 nanoTime 等)。每次 Record 时会更新 Histogram 并更新自己实现的计时器。

1.2. Reporter

用于将 metric 指标数据导出到具体的某个介质。

IoTDB 主要使用了 IoTDBReporter、PrometheusReporter、JMXReporter 三种。因此本文主要探究 DropWizard 中对应的 InfluxDBReporter、GraphiteReporter、JMXReporter 三种 Reporter

1.2.1. InfluxDBReporter

  • 设计思想: InfluxDB 报告器的设计思想是将度量数据发送到 InfluxDB,以便进行高性能的存储和查询。
  • 具体实现: InfluxDB 报告器使用 HTTP 协议将度量数据发送到 InfluxDB 服务器。它将度量名称、值和标签(tags)映射到 InfluxDB 中的数据点,并将其存储在数据库中。

1.2.2. GraphiteReporter

  • 设计思想: Graphite报告器的设计思想是将度量数据发送到Graphite,一个可扩展的度量数据存储和可视化工具,以便长期存储和绘制度量图表。
  • 具体实现: Graphite报告器使用TCP或UDP协议将度量数据发送到Graphite服务器。它将度量名称和值映射到Graphite中的度量路径,并定期将数据发送到服务器。

1.2.3. JMXReporter

  • 设计思想: 将 Metric 注册为 MBean,随后将度量数据以Java管理扩展(JMX)的方式导出,以便通过JMX客户端监视和管理应用程序。
  • 具体实现: 将度量数据注册到JMX服务器中,然后可以使用JMX客户端连接到服务器,查看和管理度量数据。实现了 JMXListener(本质上也是个 MetricRegistry,监听主 Registry)
    • 每次 registry 创建了一个 metric 对象后,在 JMX 中深 clone 一份 JMXMetric,并将其注册为 MBean

2. 性能测试

本节主要目的是全面测试对比 Micrometer 和 DropWizard 的性能优劣,从而在算法库参数上做出取舍。

By JMH benchmark

2.1. Counter

测试代码:

import com.codahale.metrics.MetricRegistry;
import io.micrometer.core.instrument.Counter;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.dropwizard.DropwizardCounter;
import io.micrometer.prometheus.PrometheusConfig;
import io.micrometer.prometheus.PrometheusMeterRegistry;
import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;

import java.util.concurrent.TimeUnit;

// 指定 Benchmark,测试多线程性能
@State(Scope.Benchmark)
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@BenchmarkMode(Mode.AverageTime)
@Warmup(iterations = 1)
@Measurement(iterations = 2)
public class CounterBenchmark {

public static void main(String[] args) throws RunnerException {
Options opt = new OptionsBuilder()
.include(CounterBenchmark.class.getSimpleName())
.build();

new Runner(opt).run();
}

private MeterRegistry micrometerRegistry;

private MetricRegistry dropwizardRegistry;

private Counter micrometerCounter;

private com.codahale.metrics.Counter dropwizardCounter;

@Setup
public void setup() {
micrometerRegistry = new SimpleMeterRegistry();;
micrometerCounter = micrometerRegistry.counter("micrometerCounter");

dropwizardRegistry = new MetricRegistry();
dropwizardCounter = dropwizardRegistry.counter("dropwizardCounter");
}

@Benchmark
public void dropwizardCountSum() {
for (int i = 0; i < 100; i++) {
dropwizardCounter.inc();
}
}

@Benchmark
public void micrometerCountSum() {
for (int i = 0; i < 100; i++) {
micrometerCounter.increment();
}
}
}

测试结果:

> Task :micrometer-benchmarks-core:CounterBenchmark.main()
# JMH version: 1.37
# VM version: JDK 17.0.8.1, OpenJDK 64-Bit Server VM, 17.0.8.1+8-LTS
# VM invoker: /Users/pengjunzhi/Library/Java/JavaVirtualMachines/corretto-17.0.8.1/Contents/Home/bin/java
# VM options: -Dfile.encoding=UTF-8 -Duser.country=CN -Duser.language=zh -Duser.variant
# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
# Warmup: 1 iterations, 10 s each
# Measurement: 2 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: io.micrometer.benchmark.core.CounterBenchmark.dropwizardCountSum

# Run progress: 0.00% complete, ETA 00:05:00
# Fork: 1 of 5
# Warmup Iteration 1: 504.794 ns/op
Iteration 1: 506.459 ns/op
Iteration 2: 506.261 ns/op

# Run progress: 10.00% complete, ETA 00:04:31
# Fork: 2 of 5
# Warmup Iteration 1: 506.972 ns/op
Iteration 1: 505.873 ns/op
Iteration 2: 498.922 ns/op

# Run progress: 20.00% complete, ETA 00:04:01
# Fork: 3 of 5
# Warmup Iteration 1: 506.325 ns/op
Iteration 1: 506.829 ns/op
Iteration 2: 504.362 ns/op

# Run progress: 30.00% complete, ETA 00:03:32
# Fork: 4 of 5
# Warmup Iteration 1: 503.179 ns/op
Iteration 1: 503.631 ns/op
Iteration 2: 518.545 ns/op

# Run progress: 40.00% complete, ETA 00:03:01
# Fork: 5 of 5
# Warmup Iteration 1: 509.092 ns/op
Iteration 1: 509.741 ns/op
Iteration 2: 505.743 ns/op


Result "io.micrometer.benchmark.core.CounterBenchmark.dropwizardCountSum":
506.637 ±(99.9%) 7.589 ns/op [Average]
(min, avg, max) = (498.922, 506.637, 518.545), stdev = 5.020
CI (99.9%): [499.048, 514.225] (assumes normal distribution)


# JMH version: 1.37
# VM version: JDK 17.0.8.1, OpenJDK 64-Bit Server VM, 17.0.8.1+8-LTS
# VM invoker: /Users/pengjunzhi/Library/Java/JavaVirtualMachines/corretto-17.0.8.1/Contents/Home/bin/java
# VM options: -Dfile.encoding=UTF-8 -Duser.country=CN -Duser.language=zh -Duser.variant
# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
# Warmup: 1 iterations, 10 s each
# Measurement: 2 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: io.micrometer.benchmark.core.CounterBenchmark.micrometerCountSum

# Run progress: 50.00% complete, ETA 00:02:31
# Fork: 1 of 5
# Warmup Iteration 1: 761.443 ns/op
Iteration 1: 750.091 ns/op
Iteration 2: 717.163 ns/op

# Run progress: 60.00% complete, ETA 00:02:01
# Fork: 2 of 5
# Warmup Iteration 1: 730.985 ns/op
Iteration 1: 786.655 ns/op
Iteration 2: 583.315 ns/op

# Run progress: 70.00% complete, ETA 00:01:30
# Fork: 3 of 5
# Warmup Iteration 1: 564.985 ns/op
Iteration 1: 567.606 ns/op
Iteration 2: 675.625 ns/op

# Run progress: 80.00% complete, ETA 00:01:00
# Fork: 4 of 5
# Warmup Iteration 1: 626.955 ns/op
Iteration 1: 560.499 ns/op
Iteration 2: 692.164 ns/op

# Run progress: 90.00% complete, ETA 00:00:30
# Fork: 5 of 5
# Warmup Iteration 1: 720.045 ns/op
Iteration 1: 733.850 ns/op
Iteration 2: 753.365 ns/op


Result "io.micrometer.benchmark.core.CounterBenchmark.micrometerCountSum":
682.033 ±(99.9%) 125.825 ns/op [Average]
(min, avg, max) = (560.499, 682.033, 786.655), stdev = 83.225
CI (99.9%): [556.208, 807.858] (assumes normal distribution)


# Run complete. Total time: 00:05:02

REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.

NOTE: Current JVM experimentally supports Compiler Blackholes, and they are in use. Please exercise
extra caution when trusting the results, look into the generated code to check the benchmark still
works, and factor in a small probability of new VM bugs. Additionally, while comparisons between
different JVMs are already problematic, the performance difference caused by different Blackhole
modes can be very significant. Please make sure you use the consistent Blackhole mode for comparisons.

Benchmark Mode Cnt Score Error Units
CounterBenchmark.dropwizardCountSum avgt 10 506.637 ± 7.589 ns/op
CounterBenchmark.micrometerCountSum avgt 10 682.033 ± 125.825 ns/op

结论:Dropwizard 性能优于 Micrometer,比例约为20%

2.2. Gauge

二者都是寄存某个对象值,在需要取的时候进行更新。其性能取决于具体的 get() 函数,故此处不做测试。

PS:DropWizard 使用了 CachedGauge,在计算密集的场景下会拥有更好的性能

2.3. Histogram

测试代码:

import com.codahale.metrics.Histogram;
import com.codahale.metrics.MetricRegistry;
import io.micrometer.core.instrument.DistributionSummary;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Tag;
import io.micrometer.core.instrument.Tags;
import io.micrometer.core.instrument.simple.SimpleMeterRegistry;
import io.micrometer.prometheus.PrometheusConfig;
import io.micrometer.prometheus.PrometheusMeterRegistry;
import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;

import java.util.concurrent.TimeUnit;

// 指定 Benchmark,测试多线程性能
@State(Scope.Benchmark)
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@BenchmarkMode(Mode.AverageTime)
@Warmup(iterations = 1)
@Measurement(iterations = 2)
public class HistogramBenchmark {

public static void main(String[] args) throws RunnerException {
Options opt = new OptionsBuilder()
.include(HistogramBenchmark.class.getSimpleName())
.build();

new Runner(opt).run();
}

private MeterRegistry micrometerRegistry;

private MetricRegistry dropwizardRegistry;

private Histogram dropwizardHistogram;

private DistributionSummary micrometerHistogram;

private Tags tags = Tags.of("key", "value", "key2", "value2", "key3", "value3", "key4", "value4", "key5", "value5");

@Setup
public void setup() {
micrometerRegistry = new SimpleMeterRegistry();
micrometerHistogram =
io.micrometer.core.instrument.DistributionSummary.builder("micrometerHistogram")
.tags(tags)
.publishPercentiles(0.5, 0.99)
.register(micrometerRegistry);

dropwizardRegistry = new MetricRegistry();
dropwizardHistogram = dropwizardRegistry.histogram("dropwizardHistogram");
}

@Benchmark
public void dropwizardRecord() {
for (int i = 0; i < 100; i++) {
dropwizardHistogram.update(i);
dropwizardHistogram.getCount();
}
}

@Benchmark
public void micrometerRecord() {
for (int i = 0; i < 100; i++) {
micrometerHistogram.record(i);
micrometerHistogram.count();
}
}
}

测试结果:

# JMH version: 1.37
# VM version: JDK 17.0.8.1, OpenJDK 64-Bit Server VM, 17.0.8.1+8-LTS
# VM invoker: /Users/pengjunzhi/Library/Java/JavaVirtualMachines/corretto-17.0.8.1/Contents/Home/bin/java
# VM options: -Dfile.encoding=UTF-8 -Duser.country=CN -Duser.language=zh -Duser.variant
# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
# Warmup: 1 iterations, 10 s each
# Measurement: 2 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: io.micrometer.benchmark.core.HistogramBenchmark.dropwizardRecord

# Run progress: 0.00% complete, ETA 00:05:00
# Fork: 1 of 5
# Warmup Iteration 1: 15:22:52.331 [io.micrometer.benchmark.core.HistogramBenchmark.dropwizardRecord-jmh-worker-1] DEBUG io.micrometer.common.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
10174.613 ns/op
Iteration 1: 9998.056 ns/op
Iteration 2: 10828.580 ns/op

# Run progress: 10.00% complete, ETA 00:04:32
# Fork: 2 of 5
# Warmup Iteration 1: 15:23:22.545 [io.micrometer.benchmark.core.HistogramBenchmark.dropwizardRecord-jmh-worker-1] DEBUG io.micrometer.common.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
10024.374 ns/op
Iteration 1: 9990.595 ns/op
Iteration 2: 10488.892 ns/op

# Run progress: 20.00% complete, ETA 00:04:01
# Fork: 3 of 5
# Warmup Iteration 1: 15:23:52.910 [io.micrometer.benchmark.core.HistogramBenchmark.dropwizardRecord-jmh-worker-1] DEBUG io.micrometer.common.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
10204.101 ns/op
Iteration 1: 10101.247 ns/op
Iteration 2: 10982.767 ns/op

# Run progress: 30.00% complete, ETA 00:03:31
# Fork: 4 of 5
# Warmup Iteration 1: 15:24:23.120 [io.micrometer.benchmark.core.HistogramBenchmark.dropwizardRecord-jmh-worker-1] DEBUG io.micrometer.common.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
9942.547 ns/op
Iteration 1: 10305.283 ns/op
Iteration 2: 10703.590 ns/op

# Run progress: 40.00% complete, ETA 00:03:01
# Fork: 5 of 5
# Warmup Iteration 1: 15:24:53.335 [io.micrometer.benchmark.core.HistogramBenchmark.dropwizardRecord-jmh-worker-1] DEBUG io.micrometer.common.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
9863.582 ns/op
Iteration 1: 9955.748 ns/op
Iteration 2: 10482.406 ns/op


Result "io.micrometer.benchmark.core.HistogramBenchmark.dropwizardRecord":
10383.716 ±(99.9%) 563.945 ns/op [Average]
(min, avg, max) = (9955.748, 10383.716, 10982.767), stdev = 373.015
CI (99.9%): [9819.771, 10947.662] (assumes normal distribution)


# JMH version: 1.37
# VM version: JDK 17.0.8.1, OpenJDK 64-Bit Server VM, 17.0.8.1+8-LTS
# VM invoker: /Users/pengjunzhi/Library/Java/JavaVirtualMachines/corretto-17.0.8.1/Contents/Home/bin/java
# VM options: -Dfile.encoding=UTF-8 -Duser.country=CN -Duser.language=zh -Duser.variant
# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
# Warmup: 1 iterations, 10 s each
# Measurement: 2 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: io.micrometer.benchmark.core.HistogramBenchmark.micrometerRecord

# Run progress: 50.00% complete, ETA 00:02:31
# Fork: 1 of 5
# Warmup Iteration 1: 15:25:23.556 [io.micrometer.benchmark.core.HistogramBenchmark.micrometerRecord-jmh-worker-1] DEBUG io.micrometer.common.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
6960.654 ns/op
Iteration 1: 6775.768 ns/op
Iteration 2: 6614.436 ns/op

# Run progress: 60.00% complete, ETA 00:02:00
# Fork: 2 of 5
# Warmup Iteration 1: 15:25:53.835 [io.micrometer.benchmark.core.HistogramBenchmark.micrometerRecord-jmh-worker-1] DEBUG io.micrometer.common.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
6919.224 ns/op
Iteration 1: 6918.534 ns/op
Iteration 2: 6843.185 ns/op

# Run progress: 70.00% complete, ETA 00:01:30
# Fork: 3 of 5
# Warmup Iteration 1: 15:26:24.055 [io.micrometer.benchmark.core.HistogramBenchmark.micrometerRecord-jmh-worker-1] DEBUG io.micrometer.common.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
6957.126 ns/op
Iteration 1: 6853.690 ns/op
Iteration 2: 6840.857 ns/op

# Run progress: 80.00% complete, ETA 00:01:00
# Fork: 4 of 5
# Warmup Iteration 1: 15:26:54.287 [io.micrometer.benchmark.core.HistogramBenchmark.micrometerRecord-jmh-worker-1] DEBUG io.micrometer.common.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
6924.513 ns/op
Iteration 1: 6958.296 ns/op
Iteration 2: 6813.379 ns/op

# Run progress: 90.00% complete, ETA 00:00:30
# Fork: 5 of 5
# Warmup Iteration 1: 15:27:24.499 [io.micrometer.benchmark.core.HistogramBenchmark.micrometerRecord-jmh-worker-1] DEBUG io.micrometer.common.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
7021.623 ns/op
Iteration 1: 6887.827 ns/op
Iteration 2: 6698.237 ns/op


Result "io.micrometer.benchmark.core.HistogramBenchmark.micrometerRecord":
6820.421 ±(99.9%) 155.021 ns/op [Average]
(min, avg, max) = (6614.436, 6820.421, 6958.296), stdev = 102.537
CI (99.9%): [6665.400, 6975.442] (assumes normal distribution)


# Run complete. Total time: 00:05:02

REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.

NOTE: Current JVM experimentally supports Compiler Blackholes, and they are in use. Please exercise
extra caution when trusting the results, look into the generated code to check the benchmark still
works, and factor in a small probability of new VM bugs. Additionally, while comparisons between
different JVMs are already problematic, the performance difference caused by different Blackhole
modes can be very significant. Please make sure you use the consistent Blackhole mode for comparisons.

Benchmark Mode Cnt Score Error Units
HistogramBenchmark.dropwizardRecord avgt 10 10383.716 ± 563.945 ns/op
HistogramBenchmark.micrometerRecord avgt 10 6820.421 ± 155.021 ns/op

Deprecated Gradle features were used in this build, making it incompatible with Gradle 9.0.

You can use '--warning-mode all' to show the individual deprecation warnings and determine if they come from your own scripts or plugins.

For more on this, please refer to https://docs.gradle.org/8.3/userguide/command_line_interface.html#sec:command_line_warnings in the Gradle documentation.

BUILD SUCCESSFUL in 5m 6s
23 actionable tasks: 2 executed, 21 up-to-date
15:27:54: Execution finished ':micrometer-benchmarks-core:HistogramBenchmark.main()'.

结论:MicroMeter 优于 DropWizard,大约比例为 40%

2.4. Timer

测试代码:

import com.codahale.metrics.MetricRegistry;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Timer;
import io.micrometer.core.instrument.simple.SimpleMeterRegistry;
import io.micrometer.prometheus.PrometheusConfig;
import io.micrometer.prometheus.PrometheusMeterRegistry;
import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;

import java.util.concurrent.Callable;
import java.util.concurrent.TimeUnit;

// 指定 Benchmark,测试多线程性能
@State(Scope.Benchmark)
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@BenchmarkMode(Mode.AverageTime)
@Warmup(iterations = 1)
@Measurement(iterations = 2)
public class TimerBenchmark {

public static void main(String[] args) throws RunnerException {
Options opt = new OptionsBuilder()
.include(TimerBenchmark.class.getSimpleName())
.build();

new Runner(opt).run();
}

private MeterRegistry micrometerRegistry;

private MetricRegistry dropwizardRegistry;

private Timer micrometerTimer;

private com.codahale.metrics.Timer dropwizardTimer;

int x = 923;

int y = 123;

@Setup
public void setup() {
micrometerRegistry = new SimpleMeterRegistry();
micrometerTimer = micrometerRegistry.timer("micrometerTimer");

dropwizardRegistry = new MetricRegistry();
dropwizardTimer = dropwizardRegistry.timer("dropwizardTimer");

}

@Benchmark
public void micrometerSumTimedWithSupplier() {
for (int i = 0; i < 100; i++) {
micrometerTimer.record(x + y, TimeUnit.MILLISECONDS);
}
}

@Benchmark
public void dropwizardSumTimedWithSupplier() {
for (int i = 0; i < 100; i++) {
dropwizardTimer.update(x + y, TimeUnit.MILLISECONDS);
}
}

@Benchmark
public void micrometerSumTimedWithSample() {
for (int i = 0; i < 10; i++) {
Timer.Sample sample = Timer.start(micrometerRegistry);
int sum = sum();
sample.stop(micrometerTimer);
}
}

@Benchmark
public void dropwizardSumTimedWithSample() throws Exception {
for (int i = 0; i < 10; i++) {
dropwizardTimer.time(this::sum);
}
}

public int sum() {
return x + y;
}

}

测试结果:

> Task :micrometer-benchmarks-core:TimerBenchmark.main()
# JMH version: 1.37
# VM version: JDK 17.0.8.1, OpenJDK 64-Bit Server VM, 17.0.8.1+8-LTS
# VM invoker: /Users/pengjunzhi/Library/Java/JavaVirtualMachines/corretto-17.0.8.1/Contents/Home/bin/java
# VM options: -Dfile.encoding=UTF-8 -Duser.country=CN -Duser.language=zh -Duser.variant
# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
# Warmup: 1 iterations, 10 s each
# Measurement: 2 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: io.micrometer.benchmark.core.TimerBenchmark.dropwizardSumTimedWithSample

# Run progress: 0.00% complete, ETA 00:10:00
# Fork: 1 of 5
# Warmup Iteration 1: 1516.590 ns/op
Iteration 1: 1530.353 ns/op
Iteration 2: 1605.669 ns/op

# Run progress: 5.00% complete, ETA 00:09:33
# Fork: 2 of 5
# Warmup Iteration 1: 1507.719 ns/op
Iteration 1: 1488.804 ns/op
Iteration 2: 1576.604 ns/op

# Run progress: 10.00% complete, ETA 00:09:03
# Fork: 3 of 5
# Warmup Iteration 1: 1502.103 ns/op
Iteration 1: 1497.555 ns/op
Iteration 2: 1555.023 ns/op

# Run progress: 15.00% complete, ETA 00:08:32
# Fork: 4 of 5
# Warmup Iteration 1: 1556.940 ns/op
Iteration 1: 1458.053 ns/op
Iteration 2: 1505.888 ns/op

# Run progress: 20.00% complete, ETA 00:08:02
# Fork: 5 of 5
# Warmup Iteration 1: 1505.264 ns/op
Iteration 1: 1516.316 ns/op
Iteration 2: 1580.754 ns/op


Result "io.micrometer.benchmark.core.TimerBenchmark.dropwizardSumTimedWithSample":
1531.502 ±(99.9%) 70.863 ns/op [Average]
(min, avg, max) = (1458.053, 1531.502, 1605.669), stdev = 46.871
CI (99.9%): [1460.639, 1602.365] (assumes normal distribution)


# JMH version: 1.37
# VM version: JDK 17.0.8.1, OpenJDK 64-Bit Server VM, 17.0.8.1+8-LTS
# VM invoker: /Users/pengjunzhi/Library/Java/JavaVirtualMachines/corretto-17.0.8.1/Contents/Home/bin/java
# VM options: -Dfile.encoding=UTF-8 -Duser.country=CN -Duser.language=zh -Duser.variant
# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
# Warmup: 1 iterations, 10 s each
# Measurement: 2 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: io.micrometer.benchmark.core.TimerBenchmark.dropwizardSumTimedWithSupplier

# Run progress: 25.00% complete, ETA 00:07:32
# Fork: 1 of 5
# Warmup Iteration 1: 12358.755 ns/op
Iteration 1: 12309.136 ns/op
Iteration 2: 12922.583 ns/op

# Run progress: 30.00% complete, ETA 00:07:02
# Fork: 2 of 5
# Warmup Iteration 1: 12072.889 ns/op
Iteration 1: 11971.788 ns/op
Iteration 2: 12708.188 ns/op

# Run progress: 35.00% complete, ETA 00:06:32
# Fork: 3 of 5
# Warmup Iteration 1: 12240.725 ns/op
Iteration 1: 12189.390 ns/op
Iteration 2: 12794.850 ns/op

# Run progress: 40.00% complete, ETA 00:06:02
# Fork: 4 of 5
# Warmup Iteration 1: 11909.155 ns/op
Iteration 1: 12186.550 ns/op
Iteration 2: 13181.730 ns/op

# Run progress: 45.00% complete, ETA 00:05:31
# Fork: 5 of 5
# Warmup Iteration 1: 12192.867 ns/op
Iteration 1: 12209.921 ns/op
Iteration 2: 12930.563 ns/op


Result "io.micrometer.benchmark.core.TimerBenchmark.dropwizardSumTimedWithSupplier":
12540.470 ±(99.9%) 624.765 ns/op [Average]
(min, avg, max) = (11971.788, 12540.470, 13181.730), stdev = 413.243
CI (99.9%): [11915.705, 13165.235] (assumes normal distribution)


# JMH version: 1.37
# VM version: JDK 17.0.8.1, OpenJDK 64-Bit Server VM, 17.0.8.1+8-LTS
# VM invoker: /Users/pengjunzhi/Library/Java/JavaVirtualMachines/corretto-17.0.8.1/Contents/Home/bin/java
# VM options: -Dfile.encoding=UTF-8 -Duser.country=CN -Duser.language=zh -Duser.variant
# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
# Warmup: 1 iterations, 10 s each
# Measurement: 2 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: io.micrometer.benchmark.core.TimerBenchmark.micrometerSumTimedWithSample

# Run progress: 50.00% complete, ETA 00:05:01
# Fork: 1 of 5
# Warmup Iteration 1: 520.268 ns/op
Iteration 1: 520.347 ns/op
Iteration 2: 515.323 ns/op

# Run progress: 55.00% complete, ETA 00:04:31
# Fork: 2 of 5
# Warmup Iteration 1: 516.566 ns/op
Iteration 1: 520.164 ns/op
Iteration 2: 509.640 ns/op

# Run progress: 60.00% complete, ETA 00:04:01
# Fork: 3 of 5
# Warmup Iteration 1: 509.843 ns/op
Iteration 1: 507.147 ns/op
Iteration 2: 506.309 ns/op

# Run progress: 65.00% complete, ETA 00:03:31
# Fork: 4 of 5
# Warmup Iteration 1: 510.824 ns/op
Iteration 1: 504.709 ns/op
Iteration 2: 505.124 ns/op

# Run progress: 70.00% complete, ETA 00:03:00
# Fork: 5 of 5
# Warmup Iteration 1: 509.629 ns/op
Iteration 1: 516.369 ns/op
Iteration 2: 501.427 ns/op


Result "io.micrometer.benchmark.core.TimerBenchmark.micrometerSumTimedWithSample":
510.656 ±(99.9%) 10.354 ns/op [Average]
(min, avg, max) = (501.427, 510.656, 520.347), stdev = 6.849
CI (99.9%): [500.302, 521.010] (assumes normal distribution)


# JMH version: 1.37
# VM version: JDK 17.0.8.1, OpenJDK 64-Bit Server VM, 17.0.8.1+8-LTS
# VM invoker: /Users/pengjunzhi/Library/Java/JavaVirtualMachines/corretto-17.0.8.1/Contents/Home/bin/java
# VM options: -Dfile.encoding=UTF-8 -Duser.country=CN -Duser.language=zh -Duser.variant
# Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
# Warmup: 1 iterations, 10 s each
# Measurement: 2 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: io.micrometer.benchmark.core.TimerBenchmark.micrometerSumTimedWithSupplier

# Run progress: 75.00% complete, ETA 00:02:30
# Fork: 1 of 5
# Warmup Iteration 1: 2741.534 ns/op
Iteration 1: 2716.235 ns/op
Iteration 2: 2762.197 ns/op

# Run progress: 80.00% complete, ETA 00:02:00
# Fork: 2 of 5
# Warmup Iteration 1: 2764.662 ns/op
Iteration 1: 2788.028 ns/op
Iteration 2: 2801.328 ns/op

# Run progress: 85.00% complete, ETA 00:01:30
# Fork: 3 of 5
# Warmup Iteration 1: 2775.788 ns/op
Iteration 1: 2794.196 ns/op
Iteration 2: 2833.326 ns/op

# Run progress: 90.00% complete, ETA 00:01:00
# Fork: 4 of 5
# Warmup Iteration 1: 2793.570 ns/op
Iteration 1: 2774.927 ns/op
Iteration 2: 2818.794 ns/op

# Run progress: 95.00% complete, ETA 00:00:30
# Fork: 5 of 5
# Warmup Iteration 1: 2773.815 ns/op
Iteration 1: 2752.855 ns/op
Iteration 2: 2816.498 ns/op


Result "io.micrometer.benchmark.core.TimerBenchmark.micrometerSumTimedWithSupplier":
2785.839 ±(99.9%) 53.348 ns/op [Average]
(min, avg, max) = (2716.235, 2785.839, 2833.326), stdev = 35.287
CI (99.9%): [2732.490, 2839.187] (assumes normal distribution)


# Run complete. Total time: 00:10:03

REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.

NOTE: Current JVM experimentally supports Compiler Blackholes, and they are in use. Please exercise
extra caution when trusting the results, look into the generated code to check the benchmark still
works, and factor in a small probability of new VM bugs. Additionally, while comparisons between
different JVMs are already problematic, the performance difference caused by different Blackhole
modes can be very significant. Please make sure you use the consistent Blackhole mode for comparisons.

Benchmark Mode Cnt Score Error Units
TimerBenchmark.dropwizardSumTimedWithSample avgt 10 1531.502 ± 70.863 ns/op
TimerBenchmark.dropwizardSumTimedWithSupplier avgt 10 12540.470 ± 624.765 ns/op
TimerBenchmark.micrometerSumTimedWithSample avgt 10 510.656 ± 10.354 ns/op
TimerBenchmark.micrometerSumTimedWithSupplier avgt 10 2785.839 ± 53.348 ns/op

结论:无论是直接更新抑或是通过 Sample 记录时间更新,Micrometer 均明显优于 DropWizard,大约比例为 300%;

2.5. Rate

MicroMeter 没有提供 Rate 语义的实现,目前 IoTDB 都使用的是 DropWizard base

3. 优化方案

3.1. 监控项选择参数

经过测试,决定选择 Micrometer 为 IoTDB Metric 系统的 baseline,在参数上舍弃 DropWizard 。理由如下

  1. Micrometer 在实现时基于 DropWizard ,可以理解为是 DropWizard 的扩展。因此 Micrometer 在功能上可以完全覆盖 DropWizard,在可拓展性上比 DropWizard 更好。

  2. 经过性能测试,除了 Counter 和 Gauge,IoTDB 现有的 Micrometer base 监控指标性能均优于 DropWizard base 监控指标(M 比 D 普遍性能优越40%以上)

    1. 而 Micrometer base 的 Counter 和 Gauge 优化项也比较清晰,经过优化后,可以达到 DropWizard base 的性能表现。
  3. 截止 2023.10.23,无论是 issue 数还是 commit 数 Micrometer 均大于 DropWizard,说明前者社区更活跃。

3.2. 【优化一】MetricType

3.2.1 Gauge

  1. 问题:

由于 Micrometer 没有提供缓存版 gauge,因此在涉及读密集且重计算的场景时会有性能问题,预期不如 Dropwizard。考虑在 IoTDB 实现时加一层缓存进行优化。

image-20231115182140973

  1. 优化:

加一个 cache,在失效时间内,如果反复读 gauge,直接返回 cache 的值。如果超过超时时间,重新调用计算函数 ref.get(),并更新 cache。

组内大佬 review:由于主要调用是 promethus,15s 一次,并发性不高。该优化意义不是特别大,考虑作为写个新类,作为用户的 option

3.2.2. Rate

  1. 问题:

原生 Rate 的更新和计算有大量冗余逻辑。

image-20231115182211527

  1. 优化:

考虑从 m1、m5、m15 中删去其二。

3.2.3. Counter

  1. 问题:

使用 DoubleAdder 作为 value 的容器但是 IoTDB 的最终接口是 long,而 double 本身的运算开销也较大,因此涉及一些转化和计算开销

image-20231115182222612

image-20231115182231480

  1. 优化:

考虑使用 LongAdder 实现 Counter。

3.2.4. DistributionSummary / IoTDB Histogram

  1. 问题:
    1. 从前面分析可以看到,Micrometer 在每次写入数据时,对 ringBuffer 的所有 bucket 都进行了写入操作。
    2. 从前面分析可以看到,当数据超过 hdrHistogram 范围时,会发生 resize,该操作有时间开销。目前的上下界 [1, 127] 显然范围有点小了,在大值数据场景下显然要 resize,甚至多次 resize。
  2. 优化:
    1. 可以通过缩小 ringBuffer 的 size,从而减少写 bucket 次数,来提高 Micrometer Histogram 的写入效率
      1. ringBuffer.length 默认设置为 3。根据上文,只要保证 ringBuffer.length 大于 1 既能保证淘汰旧数据的目的。因此考虑将 ringBuffer.length 设为 2(PR: https://github.com/apache/iotdb/pull/11500)
    2. 可以对每一个 timer/histogram 的使用场景预估数据区间,提前为每一个 timer/histogram 定制数据上下界,尽量避免 resize 操作。
      1. 由于 Micrometer 没有暴露定制化 hdrHistogram 区间范围的 API,该改动阻塞。已向他们提 issue(https://github.com/micrometer-metrics/micrometer/issues/4327)

3.2.5. Timer

从火焰图和上文的分析中可以看出,Timer 主要耗时由 histogram 的更新和自己实现计时器的更新组成。

image-20231115182245840

由于 Timer 底层使用 Histogram(前文分析过),因此优化 Histogram 也可以优化 Timer,此处不再赘述。

3.3. 【优化二】架构

3.3.1. IoTDBManager

完全删去原有的 io.micrometer.core.instrument.simple.SimpleMeterRegistry,将各项 Metric 的创建由 Registry 接管过来。这样优化的好处如下

  1. 完全适配 IoTDB 自己的命名系统,舍弃 Micrometer 的命名系统

  2. 由于不再借助 io.micrometer.core.instrument.simple.SimpleMeterRegistry 创建、管理、存储各项 Metric,使得不用再在 io.micrometer.core.instrument.simple.SimpleMeterRegistry 中创建 MetricMap,节省一倍内存

  3. 舍弃原有的 JmxReporter,自己实现一套 JmxReporter,节省一倍内存。本文 3.4.2 会详细介绍设计以及优化点)

3.3.1.1. 各指标的自主创建流程

  1. Gauge

IoTDBGauge 的核心就是 AtomicLong。由于舍弃了 Micrometer 的命名系统,因此创建 IoTDBGauge 只需 new AtomicLong() 即可。

image-20231115182308733

  1. AutoGauge

IoTDBAutoGauge 主要修改了 WeakReference 的引用。

image-20231115182325099

在原本实现中传入 WeakReferencemeterRegistry.gauge(...) 中, meterRegistry.gauge(...) 返回的仅仅就是参数中的 object。因此这里直接将WeakReference 的参数改为了 object

至于在 meterRegistry.gauge 中创建的 gaugeIoTDBAutoGauge 并没有用到,原来的实现只是为了在 Micrometer 的命名系统中创建一个同名 gauge

image-20231115182339161

  1. Counter

完全舍弃掉 Micrometer 的实现,只保留 LongAdder

image-20231115182349453

  1. Rate

IoTDB 的实现在 Micrometer 的基础上砍去了 m5、m15 等统计点,因此传入 IoTDB 定制的 IoTDBMovingAverage 即可

image-20231115182401836

  1. Timer

参考 SimpleMeterRegistry 的创建流程。经验证,创建后的 CumulativeTimer 与原来的实现属性一致,符合预期。

image-20231115182414059

  1. Histogram

参考 SimpleMeterRegistry 的创建流程。经验证,创建后的 CumulativeDistributionSummary 与原来的实现属性一致,符合预期。

image-20231115182423894

3.3.2. JmxReporter

舍弃 io.micrometer.jmx.JmxMeterRegistry 的实现,自己实现 JmxReporter这样优化的好处主要是节省一倍内存,原因如下:

io.micrometer.jmx.JmxMeterRegistry 的实现是将 JmxReporter 监听 Registry,每次 Registry 创建新指标项时,JmxReporter 也创建一份实现了 MBean 接口的指标对象,相当于一个监控项创建了两个对象

image-20231115182434178

image-20231115182441959

IoTDBJmxReporter 的设计思路是:

  1. 所有指标项天然实现 MBean 接口

image-20231115182457114

image-20231115182508237

  1. IoTDBJmxReporter 的作用仅为监听 IoTDBMetricManager,当有新指标创建时,将其注册到 JMX 中。当 ReporterType 不为 JMX 时,所有指标项不会被注册到 JMX 中。
    1. 该实现在不开启 JmxReporter 时不会有额外性能开销;在开启 JmxReporter 时,由于 JmxReporter 只需完成注册操作,相比 Micrometer 的实现少了创建对象的性能开销。

image-20231115182518746

image-20231115182529865

踩坑:MBean 的接口需要和实现类在同一个包下,且类名、接口名必须严格对应,且 objectName 必须符合 MBean 规范

  1. 实现效果:

在 org.apache.iotdb.metrics 下有各指标的 jmx 预览项。

image-20231115182542803

image-20231115182553360

4. 优化效果

  1. 环境

在某环境负载下,1C1D (IoTDB 1 ConfigNode + 1 DataNode) 测试。

  1. 火焰图实测

图中浅紫色高亮的是 metrics 部分的开销

  • 优化前(1dd5a200281aff1f42a9d7abdbde9d172445d4f6):metrics 整体占比大约在 9.79%

image-20231115182623578

优化后(a4510266fdb74e95f0cfabec36ad3f16155eaa60):metrics 整体占比大约在 **5.81%,优化了41%**的性能

image-20231115182634791

5. 总结

  1. CPU 开销:9.79% -> 5.81%,优化了 41%。

  2. 空间:由于架构上的优化,metrics 在空间占用上降低了一倍开销。

  3. 可用性:对于用户,去掉了算法库参数的选择;对于开发者,统一了原有的 Micrometer 和 DropWizard 内部实现为 metric-core,形成了 IoTDB 自己的实现方案。

6. 心得

本次性能优化的流程是:

  1. 调研 baseline(花了一周)
  2. 对比 iotdb 和 baseline,找出冗余点(花了半周)
  3. 性能测试,对比 baseline(花了半周)
  4. 跑火焰图,分析目标函数瓶颈(花了一天)
  5. 结合上述资料,尝试代码改造。改造的思路如下:
    1. 能不能串行改并行?(no)
    2. 能不能同步改异步?(no)
    3. 有没有冗余逻辑,能不能删掉?(yes)
    4. 有没有计算密集场景,能不能加缓存?(yes)
    5. 其他杂项开销(如 double 和 long 的转化,CompositeMeterRegistry 等)
    6. 补充:批处理;拆锁;

其中在火焰图上有一个 trick 的积累:idea 可以继承 async-profiler 进行火焰图分析,并可以很方便的查看结果、统计各阶段耗时比例、查看调用树等。

  1. 配置

打开 setting,新增 CPU profiler。options 经个人测试,填写event=cpu,interval=1ms的实际体验比较好

image-20231115182705428

  1. 使用

在 run 项目时选中 profiler 即可

image-20231115182714816

  1. 查看结果

image-20231115182725287

Ref

  1. https://izualzhy.cn/dropwizard-metrics#14-histograms
  2. https://metrics.dropwizard.io/4.1.1
  3. https://www.fortra.com/resources/guides/unix-load-average-part-1-how-it-works
  4. https://www.cnblogs.com/mindforward/p/15792132.html
  5. https://zhuanlan.zhihu.com/p/29178293
  6. https://metrics.dropwizard.io/4.2.0/manual/core.html#
  7. https://micrometer.io/docs/observation
  8. https://www.baeldung.com/dropwizard-metrics
  9. https://caorong.github.io/2020/08/03/quartile-%20algorithm/
  10. https://zhuanlan.zhihu.com/p/568777601
  11. https://cxybb.com/article/superice_/121311005
  12. https://caorong.github.io/2016/07/31/hdrhistogram/
OLDER > < NEWER