你有些困惑是因为 DW Metrics Timer 实际上就是 DW Metrics Meter 中的一种。
Meter 只关注速率,以 Hz(每秒事件数)为单位进行测量。每个Meter会发布4个不同的指标:
- Metrics 启动以来的平均速率
- 1、5和15分钟滚动平均速率
你可以通过在代码中不同点记录一个值来使用Meter——DW Metrics会自动记录每次调用的壁钟时间和你提供的值,并使用这些信息计算该值增加的速率:
Meter getRequests = registry.meter("some-operation.operations")
getRequests.mark() //resets the value, e.g. sets it to 0
int numberOfOps = doSomeNumberOfOperations() //takes 10 seconds, returns 333
getRequests.mark(numberOfOps) //sets the value to number of ops.
根据两次调用mark()之间的时间为10秒,发生了333次操作,我们期望我们的速率为33.3 Hz。
Timer计算这4个指标(把每个Timer.Context视为一个事件),并添加一些其他度量指标:
- 事件数计数
- 自Metrics启动以来看到的最小、平均和最大持续时间
- 标准差
- “直方图”,记录分布在50th、97th、98th、99th和99.95百分位上的持续时间
每个Timer报告了大约15个指标。
简而言之: Timer报告了大量指标,虽然它们有点棘手,但一旦您理解了它们,它们是发现尖峰行为的强大方式。
事实是,只收集两个点之间花费的时间并不是一个非常有用的指标。考虑这样的代码块:
Timer timer = registry.timer("costly-operation.service-time")
Timer.Context context = timer.time()
costlyOperation() //service time 10 ms
context.stop()
假设costlyOperation()
具有恒定的成本、恒定的负载,并在单个线程上运行。在1分钟报告期内,我们应该期望将此操作计时6000次。显然,我们不会报告实际的服务时间超过6000x -- 相反,我们需要一些方式来总结所有这些操作以适应我们所需的报告窗口。DW Metrics的计时器可以为我们自动完成此操作,每分钟(我们的报告周期)执行一次。5分钟后,我们的指标注册表将报告:
- 100(每秒事件数)
- 1分钟均值速率为100
- 5分钟均值速率为100
- 30000的计数(总事件数)
- 最大值为10(毫秒)
- 最小值为10
- 平均值为10
- 50百分位(p50)值为10
- 99.9百分位(p999)值为10
现在,让我们考虑一个情况,即偶尔会出现一个完全偏离轨道并阻塞了很长时间的操作:
Timer timer = registry.timer("costly-operation.service-time")
Timer.Context context = timer.time()
costlyOperation() //takes 10 ms usually, but once every 1000 times spikes to 1000 ms
context.stop()
在1分钟的收集期内,我们现在会看到少于6000个执行,因为每1000个执行中有一个需要更长时间。大约是5505次。在这之后的第一分钟(总共6分钟的系统时间)中,我们现在会看到:
- 平均速率为98(每秒事件数)
- 1分钟平均速率为91.75
- 5分钟平均速率为98.35
- 计数为35505(总事件数)
- 最大持续时间为1000(毫秒)
- 最小持续时间为10
- 平均持续时间为10.13
- 50th百分位数(p50)值为10
- 99.9th百分位数(p999)值为1000
如果你将这些数据绘制成图表,你会发现大部分请求(p50、p75、p99等)都能在10毫秒内完成,但其中每1000个请求中会有一个请求(p99)需要1秒钟才能完成。这也会导致平均速率略微下降(约2%),1分钟平均速率显著下降(近9%)。
如果你只看平均值(速率或持续时间),你永远不会发现这些突发事件——当它们与大量成功操作平均时,它们会被淹没在背景噪音中。同样,仅仅知道最大值也没有多大用处,因为它不能告诉你最大值发生的频率。这就是直方图成为跟踪性能的强大工具的原因,也是 DW Metrics' Timer 发布速率和直方图的原因。