java - DropWizard Metrics Meters vs Timers

codahale-metrics

Question

Estoy aprendiendo la biblioteca de métricas DropWizard (anteriormente métricas Coda Hale) y estoy confundido sobre cuándo debería usar Meters vs Timers . Según los documentos:

Medidor: un medidor mide la velocidad a la que ocurre un conjunto de eventos

y:

Temporizador: un temporizador es básicamente un histograma de la duración de un tipo de evento y un medidor de la frecuencia de su ocurrencia

Basado en estas definiciones, no puedo discernir la diferencia entre estas. Lo que me confunde es que Timer no se usa de la forma en que esperaba que se usara. Para mí, Timer es solo eso: un temporizador; debería medir la diferencia de tiempo entre un start() y una stop() . Pero parece que los Timers también capturan las tasas a las que ocurren los eventos, lo que se siente como si estuvieran pisando los dedos del pie.

Si pudiera ver un ejemplo de lo que genera cada componente que podría ayudarme a comprender cuándo / dónde usar cualquiera de estos.

Answer 1

Está confundido en parte porque un temporizador de métricas DW es , entre otras cosas, un medidor de métricas DW.

Un medidor se ocupa exclusivamente de las tasas, medidas en Hz (eventos por segundo). Cada medidor da como resultado que se publiquen 4 (?) Métricas distintas:

• una tasa media (promedio) desde que se iniciaron las métricas
• Tasas medias continuas de 1, 5 y 15 minutos

Utiliza un medidor registrando un valor en diferentes puntos de su código: DW Metrics anota automáticamente el tiempo de bloqueo de cada llamada junto con el valor que le dio, y los utiliza para calcular la velocidad a la que ese valor aumenta:

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.

Esperaríamos que nuestras tasas fueran de 33.3 Hz, ya que ocurrieron 333 operaciones y el tiempo entre las dos llamadas para marcar () fue de 10 segundos.

Un temporizador calcula estas 4 métricas anteriores (considerando cada Timer.Context como un evento) y les agrega varias métricas adicionales:

• un recuento de la cantidad de eventos
• Duración mínima, media y máxima observadas desde el inicio de las métricas
• Desviación Estándar
• un "histograma", que registra la duración distribuida en los percentiles 50, 97, 98, 99 y 99.95

Hay algo así como 15 métricas totales reportadas para cada temporizador.

En resumen : los temporizadores informan MUCHAS métricas, y pueden ser difíciles de entender, pero una vez que lo hacen, son una forma bastante poderosa de detectar el comportamiento espinoso.

El hecho es que simplemente recopilar el tiempo dedicado entre dos puntos no es una métrica terriblemente útil. Considere: tiene un bloque de código como este:

Timer timer = registry.timer("costly-operation.service-time")
Timer.Context context = timer.time()
costlyOperation() //service time 10 ms
context.stop()

Supongamos que costlyOperation () tiene un costo constante, una carga constante y opera en un solo hilo. Dentro de un período de informe de 1 minuto, debemos esperar cronometrar esta operación 6000 veces. Obviamente, no informaremos el tiempo de servicio real a través del cable 6000x; en cambio, necesitamos alguna forma de resumir todas esas operaciones para que se ajusten a nuestra ventana de informes deseada. El temporizador de DW Metrics hace esto por nosotros, automáticamente, una vez por minuto (nuestro período de informe). Después de 5 minutos, nuestro registro de métricas informaría:

• una tasa de 100 (eventos por segundo)
• una tasa media de 1 minuto de 100
• una tasa media de 5 minutos de 100
• un recuento de 30000 (eventos totales vistos)
• un máximo de 10 (ms)
• un mínimo de 10
• una media de 10
• un valor del percentil 50 (p50) de 10
• un valor de percentil 99.9 (p999) de 10

Ahora, consideremos que ingresamos en un período en el que ocasionalmente nuestra operación se sale completamente de los rieles y se bloquea durante un período prolongado:

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()

Durante un período de recopilación de 1 minuto, ahora veríamos menos de 6000 ejecuciones, ya que cada 1000a ejecución lleva más tiempo. Resulta alrededor de 5505. Después del primer minuto (6 minutos de tiempo total del sistema) de esto, ahora veríamos:

• una tasa media de 98 (eventos por segundo)
• una tasa media de 1 minuto de 91.75
• una tasa media de 5 minutos de 98.35
• un recuento de 35505 (eventos totales vistos)
• una duración máxima de 1000 (ms)
• una duración mínima de 10
• una duración media de 10,13
• un valor del percentil 50 (p50) de 10
• un valor de percentil 99.9 (p999) de 1000

Si graficara esto, vería que la mayoría de las solicitudes (p50, p75, p99, etc.) se completaron en 10 ms, pero una solicitud de 1000 (p99) se completó en 1s. Esto también se vería como una ligera reducción en la tasa promedio (aproximadamente 2%) y una reducción considerable en la media de 1 minuto (casi 9%).

Si solo observa los medios a lo largo del tiempo (velocidad o duración), nunca detectará estos picos: se arrastran al ruido de fondo cuando se promedian con muchas operaciones exitosas. Del mismo modo, conocer el máximo no es útil, porque no te dice con qué frecuencia ocurre el máximo. Esta es la razón por la cual los histogramas son una herramienta poderosa para rastrear el rendimiento, y por qué el temporizador de DW Metrics publica una tasa Y un histograma.