【问题标题】:DropWizard Metrics Meters vs TimersDropWizard Metrics 米与计时器
【发布时间】:2015-09-08 08:46:09
【问题描述】:

我正在学习 DropWizard Metrics library(以前的 Coda Hale 指标),我不知道什么时候应该使用 MetersTimers。根据文档:

计量器:计量器测量一组事件发生的速率

和:

计时器:计时器基本上是一种事件持续时间的直方图和事件发生率的计量器

根据这些定义,我无法辨别它们之间的区别。让我感到困惑的是,Timer 的使用方式并没有像我预期的那样使用。对我来说,Timer 就是:一个计时器;它应该测量start()stop() 之间的时间差异。但似乎Timers 也捕获了事件发生的速率,感觉就像他们踩到了Meters 脚趾。

如果我能看到每个组件输出的示例,这可能有助于我了解何时/何地使用其中任何一个。

【问题讨论】:

    标签: java timer dropwizard metrics codahale-metrics


    【解决方案1】:

    您感到困惑的部分原因是 DW Metrics Timer IS,除此之外,还有 DW Metrics Meter。

    仪表只关注速率,以赫兹(每秒事件数)为单位。每个 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.
    

    我们预计我们的速率为 33.3 Hz,因为发生了 333 次操作,并且两次调用 mark() 之间的时间为 10 秒。

    Timer 计算上述 4 个指标(将每个 Timer.Context 视为一个事件)并向它们添加一些额外的指标:

    • 事件数统计
    • 自 Metrics 开始以来看到的最短、平均和最长持续时间
    • 标准差
    • “直方图”,记录分布在第 50、97、98、99 和 99.95 个百分位的持续时间

    每个 Timer 总共报告了大约 15 个指标。

    简而言之:计时器报告了很多指标,它们可能难以理解,但一旦你这样做了,它们就会成为发现尖峰行为的一种非常有效的方法。


    事实是,仅收集两点之间花费的时间并不是一个非常有用的指标。考虑一下:你有一个这样的代码块:

    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 (ms)
    • 10分钟持续时间
    • 平均持续时间为 10.13
    • 第 50 个百分位数 (p50) 值为 10
    • 第 99.9 个百分位数 (p999) 值为 1000

    如果您绘制此图,您会看到大多数请求(p50、p75、p99 等)在 10 毫秒内完成,但 1000 个请求中的一个 (p99) 在 1 秒内完成。这也被视为平均比率略有下降(约 2%)和 1 分钟平均值大幅下降(接近 9%)。

    如果您只查看时间平均值(速率或持续时间),您将永远不会发现这些尖峰——当对许多成功操作进行平均时,它们会被拖入背景噪音中。同样,仅知道最大值也无济于事,因为它不会告诉您最大值出现的频率。这就是为什么直方图是跟踪性能的强大工具,也是 DW Metrics 的计时器同时发布速率和直方图的原因。

    【讨论】:

    • 一个很好的附加信息包含在here。默认情况下,计时器使用指数衰减的存储库。这意味着您看到的数据大约是过去 5 分钟的数据,而直方图值偏向于较新的数据。
    • 有没有办法在每次运行代码块时获取执行时间?除了平均费率、平均费率和其他东西之外,我还需要这个。这可能吗?
    • 如果您只是想计量和报告每次执行代码块的服务时间,那并不是指标聚合库的真正用途。在指标发生时保存指标的“存储库”可能无法为您的需求保存足够的上下文。幸运的是,您可以使用简单的日志记录或 YourKit 等 VM 检测工具轻松解决这个问题。
    • 所以这基本上意味着如果我用 "@Timed" 注释我的方法,那么用 "@Metered" 注释它也是多余的,因为 "@Timed" 无论如何都会做 "@Metered" 所做的事情?
    • @MatthewMarkMiller 但是,例如,我如何接收计时器在过去 1/5/15 分钟内测量的以毫秒为单位的 AVG 执行时间,因为我看到计时器是唯一存储的“平均值”值聚合整个应用程序生命周期的统计信息,并存储 1/5/15 分钟速率,但它们显示一些频率(每秒执行率)而不是 AVG 时间。假设在最后 5 分钟内,我有 3 个 DB 插入,执行持续时间为 1ms/2ms/3ms。所以 AVG 是 2ms。如何使用计时器获取此统计信息?