25. července 2017

DropWizard Metrics


DropWizard Metrics poskytují sadu nástrojů pro měření chování kritických komponent aplikací v produkčním prostředí.

Oficiální stránky projektu jsou http://metrics.dropwizard.io/


Import do projektu


Do projektu je potřeba přidat Maven závislost na metrics-core.
<dependencies>
  <dependency>
    <groupId>io.dropwizard.metrics</groupId>
    <artifactId>metrics-core</artifactId>
    <version>3.2.0</version>
  </dependency>
</dependencies>

Metriky pod pokličkou


Základní knihovna pro DropWizard Metrics je metrics-core, která poskytuje:

  • MetricRegistry (výchozí třída pro zavedení metrik)
  • 5 typů metrik
    • Gauges
    • Counters
    • Histograms
    • Meters
    • Timers
  • reporty metrik přes JMX, konzoli, CSV soubory nebo SLF4J logování

Metric Registries


Výchozím bodem pro zavedení metrik do projektu je třída MetricRegistry obsahující kolekci všech metrik, které je možno v aplikaci použít. Zpravidla stačí vytvořit jednu instanci MetricRegistry na aplikaci, ale je možné použít i více instancí, pokud chceme organizovat metriky do samostatných skupin.

Vytvoření instance třídy MetricRegistry je jednoduché
final MetricRegistry metrics = new MetricRegistry();
Není problém vytvořit instanci i jako statickou proměnnou.

Všechny třídy jednotlivých metrik jsou thread-safe.

Metric Names


Každá metrika je asociována s MetricRegistry a má jedinečný název v rámci tohoto registru. Názvy metrik se zapisují tečkovou notací, např. cz.cca.example.Queue.size. Pokud potřebujeme rozlišit dvě různé instance cz.cca.example.Queue, je možno jim dát nějaký konkrétnější název, např. cz.cca.example.Queue.requests.size a cz.cca.example.Queue.responses.size.

Třída MetricRegistry poskytuje sadu pomocných statických metod pro snadné vytváření názvů metrik:
MetricRegistry.name(Queue.class, "requests", "size")
MetricRegistry.name(Queue.class, "responses", "size")
které automaticky vytvoří požadované názvy s tečkovou notací. Nejprve sestaví přes tečkovou notaci plný název třídy (např. cz.cca.example.Queue) a dále připojí requests.size resp. responses.size.

Typy metrik


Gauges


Gauge je nejjednodušší typ metriky. Pouze vrací nějakou hodnotu. Např. pokud potřebujeme sledovat nějakou hodnotu aplikace (třeba délku fronty), můžeme ji zaregistrovat pomocí Gauge instance, která tuto hodnotu vrací.

Ukázka použití

Chceme sledovat velikost paměti (cache) ve třídě cz.cca.example.SessionStore.
registry.register(name(SessionStore.class, "cache"), new Gauge<Integer>() {
  @Override
  public Integer getValue() {
    return cache.getEvictionsCount();
  }
});
Tímto se vytvoří nová metrika Gauge pojmenovaná cz.cca.example.SessionStore.cahe, která vrací aktuální velikost obsazení cache.

Ukázkový příklad
package cz.cca.dropwizard;

import com.codahale.metrics.*;
import java.util.*;
import java.util.concurrent.*;

public class ExampleGauge {
    static final MetricRegistry metrics = new MetricRegistry();

    public static void main(String[] args) {
        final Queue queue = new LinkedList<String>();

        // Zaregistrování Gauge pro vracení délky fronty
        metrics.register(MetricRegistry.name(ExampleGauge.class, "queue", "size"),
                new Gauge<Integer>() {
                    @Override
                    public Integer getValue() {
                        return queue.size();
                    }
                });

        // Spustíme sledování metrik (výpis do konzole)
        startReport(metrics);

        waitSec(2); // Chvilku počkáme, aby se stihl vypsat počáteční stav fronty

        // Do fronty přidáme dvě hodnoty
        queue.add("A");
        queue.add("B");

        waitSec(1); // Chvilku počkáme, aby se stihl vypsat koncový stav fronty
    }

    static void startReport(MetricRegistry metrics) {
        ConsoleReporter reporter = ConsoleReporter.forRegistry(metrics)
                .convertRatesTo(TimeUnit.SECONDS)
                .convertDurationsTo(TimeUnit.MILLISECONDS)
                .build();
        reporter.start(1, TimeUnit.SECONDS);
    }

    static void waitSec(final int seconds) {
        try {
            Thread.sleep(seconds * 1000);
        }
        catch(InterruptedException e) {}
    }
}
Výstupem příkladu bude
10.3.17 7:39:55 ================================================================

-- Gauges ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleGauge.queue.size
             value = 0

10.3.17 7:39:56 ================================================================

-- Gauges ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleGauge.queue.size
             value = 2
Z výpisu je vidět velikost fronty v jednotlivých okamžicích, nejprve prázdná fronta, pak fronta s dvěma prvky. V reálné aplikaci je takto možno sledovat např. nějakou cache po celou dobu běhu aplikace.

Poznámka na okraj

Místo anonymní vnitřní třídy (jak je ukázáno níže)
// Zaregistrování Gauge pro vracení délky fronty
metrics.register(MetricRegistry.name(ExampleGauge.class, "queue", "size"),
        new Gauge<Integer>() {
            @Override
            public Integer getValue() {
                return queue.size();
            }
        });
je možné totéž zapsat pomocí lambda výrazu a ušetřit tak pár řádek kódu :-)
metrics.register(MetricRegistry.name(ExampleGauge.class, "queue", "size"), (Gauge<Integer>) () -> queue.size());

Counters


Counter je jednoduché počítadlo poskytující metody pro inkrementaci (zvýšení hodnoty) a dekrementaci (snížení hodnoty). Možno použít např. pro efektivnější způsob měření úloh čekajících ve frontě.
Ukázka použití

Chceme sledovat frontu požadavků, do metody pro vložení požadavku do fronty přidáme inkrementaci metriky, do metody pro odebrání prvku z fronty přidáme dekrementaci metriky.
private final Counter pendingJobs = metrics.counter(MetricRegistry.name(QueueManager.class, "pending-jobs"));

public void addJob(Job job) {
    // Přidání prvku do fronty
    pendingJobs.inc();
    queue.offer(job);
}

public Job takeJob() {
    // Odebrání prvku z fronty
    pendingJobs.dec();
    return queue.take();
}
Metody inc() a dec() lze volat i s parametrem, který říká, o kolik se má inkrementovat/dekrementovat.
pendingJobs.inc(5);
pendingJobs.dec(5);
Ukázkový příklad
package cz.cca.dropwizard;

import com.codahale.metrics.*;
import java.util.*;
import java.util.concurrent.*;

public class ExampleCounter {
    private static final MetricRegistry metrics = new MetricRegistry();
    private static final Counter pendingJobs = metrics.counter(MetricRegistry.name(ExampleCounter.class, "pending-jobs"));

    private static Queue queue = new LinkedList<String>();

    public static void addJob(String job) {
        // Přidání prvku do fronty
        pendingJobs.inc();
        queue.add(job);
    }

    public static String takeJob() {
        // Odebrání prvku z fronty
        pendingJobs.dec();
        return (String) queue.remove();
    }

    public static void main(String[] args) {
        startReport(metrics);

        waitSec(2);

        // Vložení 10ti prvků do fronty
        for (int i = 0; i < 10; i++) {
            addJob("Job" + i);
        }

        waitSec(1);

        // Vložení 5ti prvků do fronty
        for (int i = 0; i < 5; i++) {
            addJob("Job" + i);
        }

        waitSec(1);

        // Odebrání 10ti prvků z fronty
        for (int i = 0; i < 10; i++) {
            takeJob();
        }

        waitSec(1);
    }

    static void startReport(MetricRegistry metrics) {
        ConsoleReporter reporter = ConsoleReporter.forRegistry(metrics)
                .convertRatesTo(TimeUnit.SECONDS)
                .convertDurationsTo(TimeUnit.MILLISECONDS)
                .build();
        reporter.start(1, TimeUnit.SECONDS);
    }

    static void waitSec(final int seconds) {
        try {
            Thread.sleep(seconds * 1000);
        }
        catch(InterruptedException e) {}
    }

}
Výstup bude následující
10.3.17 9:33:51 ================================================================

-- Counters --------------------------------------------------------------------
cz.cca.dropwizard.ExampleCounter.pending-jobs
             count = 0

10.3.17 9:33:52 ================================================================

-- Counters --------------------------------------------------------------------
cz.cca.dropwizard.ExampleCounter.pending-jobs
             count = 10

10.3.17 9:33:53 ================================================================

-- Counters --------------------------------------------------------------------
cz.cca.dropwizard.ExampleCounter.pending-jobs
             count = 15

10.3.17 9:33:54 ================================================================

-- Counters --------------------------------------------------------------------
cz.cca.dropwizard.ExampleCounter.pending-jobs
             count = 5
Metrika ukazuje obsazení fronty ve sledovaných okamžicích.

Histograms


Histogram umožňuje měřit statistické rozdělení hodnot v nějakém proudu dat. Kromě minima, maxima, průměru atd. měří i medián, 75., 90., 95., 98. a 99.9. percentil.

Ukázka použití

Následující ukázka měří velikost odpovědi v bytech.
private final Histogram responseSizes = metrics.histogram(MetricRegistry.name(RequestHandler.class, "response-sizes"));

public void handleRequest(Request request, Response response) {
    // ...
    responseSizes.update(response.getContent().length);
}
Ukázkový příklad
package cz.cca.dropwizard;

import com.codahale.metrics.*;

import java.util.concurrent.TimeUnit;

public class ExampleHistogram {
    private static final MetricRegistry metrics = new MetricRegistry();
    private static final Histogram histogram = metrics.histogram(MetricRegistry.name(ExampleHistogram.class, "histogram"));

    public static void main(String[] args) {
        startReport(metrics);

        waitSec(2);

        int[][] pole = { {5, 18, 6, 27, 64, 15}, {2, 3, 93, 45, 23, 20}, {80, 50, 66, 24, 77, 61} };

        for (int i = 0; i < pole.length; i++) {
            for (int j = 0; j < pole[i].length; j++) {
                histogram.update(pole[i][j]);
                waitSec(1);
            }
        }
    }

    static void startReport(MetricRegistry metrics) {
        ConsoleReporter reporter = ConsoleReporter.forRegistry(metrics)
                .convertRatesTo(TimeUnit.SECONDS)
                .convertDurationsTo(TimeUnit.MILLISECONDS)
                .build();
        reporter.start(1, TimeUnit.SECONDS);
    }

    static void waitSec(final int seconds) {
        try {
            Thread.sleep(seconds * 1000);
        }
        catch(InterruptedException e) {}
    }
}
Výpis může vypadat následovně
10.3.17 12:14:12 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 0
               min = 0
               max = 0
              mean = 0,00
            stddev = 0,00
            median = 0,00
              75% <= 0,00
              95% <= 0,00
              98% <= 0,00
              99% <= 0,00
            99.9% <= 0,00

10.3.17 12:14:13 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 1
               min = 5
               max = 5
              mean = 5,00
            stddev = 0,00
            median = 5,00
              75% <= 5,00
              95% <= 5,00
              98% <= 5,00
              99% <= 5,00
            99.9% <= 5,00

10.3.17 12:14:14 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 2
               min = 5
               max = 18
              mean = 11,55
            stddev = 6,50
            median = 18,00
              75% <= 18,00
              95% <= 18,00
              98% <= 18,00
              99% <= 18,00
            99.9% <= 18,00

10.3.17 12:14:15 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 3
               min = 5
               max = 18
              mean = 9,67
            stddev = 5,90
            median = 6,00
              75% <= 18,00
              95% <= 18,00
              98% <= 18,00
              99% <= 18,00
            99.9% <= 18,00

10.3.17 12:14:16 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 4
               min = 5
               max = 27
              mean = 14,10
            stddev = 9,11
            median = 18,00
              75% <= 27,00
              95% <= 27,00
              98% <= 27,00
              99% <= 27,00
            99.9% <= 27,00

10.3.17 12:14:17 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 5
               min = 5
               max = 64
              mean = 24,38
            stddev = 21,75
            median = 18,00
              75% <= 27,00
              95% <= 64,00
              98% <= 64,00
              99% <= 64,00
            99.9% <= 64,00

10.3.17 12:14:18 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 6
               min = 5
               max = 64
              mean = 22,76
            stddev = 20,10
            median = 18,00
              75% <= 27,00
              95% <= 64,00
              98% <= 64,00
              99% <= 64,00
            99.9% <= 64,00

10.3.17 12:14:19 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 7
               min = 2
               max = 64
              mean = 19,66
            stddev = 19,96
            median = 15,00
              75% <= 27,00
              95% <= 64,00
              98% <= 64,00
              99% <= 64,00
            99.9% <= 64,00

10.3.17 12:14:20 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 8
               min = 2
               max = 64
              mean = 17,47
            stddev = 19,43
            median = 6,00
              75% <= 18,00
              95% <= 64,00
              98% <= 64,00
              99% <= 64,00
            99.9% <= 64,00

10.3.17 12:14:21 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 9
               min = 2
               max = 93
              mean = 26,37
            stddev = 30,44
            median = 15,00
              75% <= 27,00
              95% <= 93,00
              98% <= 93,00
              99% <= 93,00
            99.9% <= 93,00

10.3.17 12:14:22 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 10
               min = 2
               max = 93
              mean = 28,36
            stddev = 29,34
            median = 18,00
              75% <= 45,00
              95% <= 93,00
              98% <= 93,00
              99% <= 93,00
            99.9% <= 93,00

10.3.17 12:14:23 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 11
               min = 2
               max = 93
              mean = 27,84
            stddev = 27,91
            median = 18,00
              75% <= 45,00
              95% <= 93,00
              98% <= 93,00
              99% <= 93,00
            99.9% <= 93,00

10.3.17 12:14:24 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 12
               min = 2
               max = 93
              mean = 27,13
            stddev = 26,71
            median = 20,00
              75% <= 45,00
              95% <= 93,00
              98% <= 93,00
              99% <= 93,00
            99.9% <= 93,00

10.3.17 12:14:25 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 13
               min = 2
               max = 93
              mean = 31,57
            stddev = 29,47
            median = 20,00
              75% <= 45,00
              95% <= 93,00
              98% <= 93,00
              99% <= 93,00
            99.9% <= 93,00

10.3.17 12:14:26 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 14
               min = 2
               max = 93
              mean = 33,02
            stddev = 28,72
            median = 23,00
              75% <= 50,00
              95% <= 93,00
              98% <= 93,00
              99% <= 93,00
            99.9% <= 93,00

10.3.17 12:14:27 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 15
               min = 2
               max = 93
              mean = 35,46
            stddev = 28,96
            median = 23,00
              75% <= 64,00
              95% <= 93,00
              98% <= 93,00
              99% <= 93,00
            99.9% <= 93,00

10.3.17 12:14:28 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 16
               min = 2
               max = 93
              mean = 34,66
            stddev = 28,08
            median = 24,00
              75% <= 64,00
              95% <= 93,00
              98% <= 93,00
              99% <= 93,00
            99.9% <= 93,00

10.3.17 12:14:29 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 17
               min = 2
               max = 93
              mean = 37,46
            stddev = 29,11
            median = 24,00
              75% <= 66,00
              95% <= 93,00
              98% <= 93,00
              99% <= 93,00
            99.9% <= 93,00

10.3.17 12:14:30 ===============================================================

-- Histograms ------------------------------------------------------------------
cz.cca.dropwizard.ExampleHistogram.histogram
             count = 18
               min = 2
               max = 93
              mean = 38,94
            stddev = 28,75
            median = 27,00
              75% <= 64,00
              95% <= 93,00
              98% <= 93,00
              99% <= 93,00
            99.9% <= 93,00

Meters


Tato metrika měří rychlost událostí v čase (např. počet požadavků za jednu sekundu). Kromě průměrného počtu požadavků lze také sledovat klouzavé průměry za 1 minutu / 5 minut / 15 minut, což může být mnohdy zajímavější údaj než celkový proměr za celou dobu běhu (protože z klouzavých průměrů je možno vyčíst chování/zátěž aplikace v posledních minutách a získat tak aktuálnější pohled).

Ukázka použití
final Meter meterRequests = registry.meter(name(WebProxy.class, "get-requests", "requests"));
meterRequests.mark();
meterRequests.mark(requests.size());
Metrika poskytuje metodu mark(), kterou se započítá požadavek do metriky. Je možno volat i s číselným parametrem (podle potřeby).

Ukázkový příklad
package cz.cca.dropwizard;

import com.codahale.metrics.*;
import java.util.concurrent.*;

public class ExampleMeter {
    static final MetricRegistry metrics = new MetricRegistry();

    public static void main(String args[]) {
        // Spuštění reportů do konzole
        startReport();

        Meter requests = metrics.meter("requests");

        int[] reqeustsCount = { 20, 13, 69 };

        for (int i = 0; i < reqeustsCount.length; i++) {
            requests.mark(reqeustsCount[i]);
            waitSec();
        }
    }

    static void startReport() {
        ConsoleReporter reporter = ConsoleReporter.forRegistry(metrics)
                .convertRatesTo(TimeUnit.SECONDS)
                .convertDurationsTo(TimeUnit.MILLISECONDS)
                .build();
        reporter.start(1, TimeUnit.SECONDS);
    }

    static void waitSec() {
        try {
            Thread.sleep(1*1000);
        }
        catch(InterruptedException e) {}
    }
}
Výstup bude vypadat následovně
10.3.17 15:34:00 ===============================================================

-- Meters ----------------------------------------------------------------------
requests
             count = 20
         mean rate = 19,33 events/second
     1-minute rate = 0,00 events/second
     5-minute rate = 0,00 events/second
    15-minute rate = 0,00 events/second

10.3.17 15:34:01 ===============================================================

-- Meters ----------------------------------------------------------------------
requests
             count = 33
         mean rate = 16,54 events/second
     1-minute rate = 0,00 events/second
     5-minute rate = 0,00 events/second
    15-minute rate = 0,00 events/second

10.3.17 15:34:02 ===============================================================

-- Meters ----------------------------------------------------------------------
requests
             count = 102
         mean rate = 34,05 events/second
     1-minute rate = 0,00 events/second
     5-minute rate = 0,00 events/second
    15-minute rate = 0,00 events/second
Každou vteřinu se započte určitý počet požadavků, metrika zobrazuje celkový počet požadavků, kolik je průměrně požadavků za vteřinu a klouzavé průměry (ty nejsou s ohledem na krátkou dobu běhu spočteny).

Timers


Timer je v podstatě kombinace histogramu trvání nějaké akce a měřiče počtu volání akce za časový údaj (tj. metriky Histogram a Meter, ale nenahrazuje je!).

Ukázka použití
private final Timer responses = metrics.timer(MetricRegistry.name(RequestHandler.class, "responses"));

public String handleRequest(Request request, Response response) {
    final Timer.Context context = responses.time();
    try {
        // Nějaké zpracování požadavku...
        return "OK";
    }
    finally {
        context.stop();
    }
}
Ukázkový příklad

V ukázkovém příkladu je v cyklu volána nějaká akce, ve které je aplikován Timer pro započítání, kolikrát byla akce volána, s jakou periodou, jak dlouho akce trvala.

package cz.cca.dropwizard;

import com.codahale.metrics.*;
import java.util.concurrent.*;

public class ExampleTimer {
    private static final MetricRegistry metrics = new MetricRegistry();
    private static final Timer timer = metrics.timer(MetricRegistry.name(ExampleTimer.class, "timer"));

    public static void main(String[] args) {
        startReport(metrics);

        int[] delay = { 2, 1, 3, 4, 1 };

        for (int i = 0; i < delay.length; i++) {
            doWork(delay[i]);
        }

        waitSec(1);
    }

    public static void doWork(int delay) {
        final Timer.Context context = timer.time();
       
        // Touto prodlevou je simulována doba zpracování požadavku
        waitSec(delay);

        context.stop();
    }

    static void startReport(MetricRegistry metrics) {
        ConsoleReporter reporter = ConsoleReporter.forRegistry(metrics)
                .convertRatesTo(TimeUnit.SECONDS)
                .convertDurationsTo(TimeUnit.MILLISECONDS)
                .build();
        reporter.start(1, TimeUnit.SECONDS);
    }

    static void waitSec(final int seconds) {
        try {
            Thread.sleep(seconds * 1000);
        }
        catch(InterruptedException e) {}
    }
}
Výstup bude vypadat následovně
10.3.17 13:16:24 ===============================================================

-- Timers ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleTimer.timer
             count = 0
         mean rate = 0,00 calls/second
     1-minute rate = 0,00 calls/second
     5-minute rate = 0,00 calls/second
    15-minute rate = 0,00 calls/second
               min = 0,00 milliseconds
               max = 0,00 milliseconds
              mean = 0,00 milliseconds
            stddev = 0,00 milliseconds
            median = 0,00 milliseconds
              75% <= 0,00 milliseconds
              95% <= 0,00 milliseconds
              98% <= 0,00 milliseconds
              99% <= 0,00 milliseconds
            99.9% <= 0,00 milliseconds

10.3.17 13:16:25 ===============================================================

-- Timers ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleTimer.timer
             count = 1
         mean rate = 0,00 calls/second
     1-minute rate = 0,00 calls/second
     5-minute rate = 0,00 calls/second
    15-minute rate = 0,00 calls/second
               min = 0,00 milliseconds
               max = 0,00 milliseconds
              mean = 0,00 milliseconds
            stddev = 0,00 milliseconds
            median = 0,00 milliseconds
              75% <= 0,00 milliseconds
              95% <= 0,00 milliseconds
              98% <= 0,00 milliseconds
              99% <= 0,00 milliseconds
            99.9% <= 0,00 milliseconds

10.3.17 13:16:26 ===============================================================

-- Timers ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleTimer.timer
             count = 1
         mean rate = 0,33 calls/second
     1-minute rate = 0,00 calls/second
     5-minute rate = 0,00 calls/second
    15-minute rate = 0,00 calls/second
               min = 2000,02 milliseconds
               max = 2000,02 milliseconds
              mean = 2000,02 milliseconds
            stddev = 0,00 milliseconds
            median = 2000,02 milliseconds
              75% <= 2000,02 milliseconds
              95% <= 2000,02 milliseconds
              98% <= 2000,02 milliseconds
              99% <= 2000,02 milliseconds
            99.9% <= 2000,02 milliseconds

10.3.17 13:16:27 ===============================================================

-- Timers ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleTimer.timer
             count = 2
         mean rate = 0,49 calls/second
     1-minute rate = 0,00 calls/second
     5-minute rate = 0,00 calls/second
    15-minute rate = 0,00 calls/second
               min = 1000,19 milliseconds
               max = 2000,02 milliseconds
              mean = 1496,36 milliseconds
            stddev = 499,90 milliseconds
            median = 1000,19 milliseconds
              75% <= 2000,02 milliseconds
              95% <= 2000,02 milliseconds
              98% <= 2000,02 milliseconds
              99% <= 2000,02 milliseconds
            99.9% <= 2000,02 milliseconds

10.3.17 13:16:28 ===============================================================

-- Timers ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleTimer.timer
             count = 2
         mean rate = 0,40 calls/second
     1-minute rate = 0,40 calls/second
     5-minute rate = 0,40 calls/second
    15-minute rate = 0,40 calls/second
               min = 1000,19 milliseconds
               max = 2000,02 milliseconds
              mean = 1496,36 milliseconds
            stddev = 499,90 milliseconds
            median = 1000,19 milliseconds
              75% <= 2000,02 milliseconds
              95% <= 2000,02 milliseconds
              98% <= 2000,02 milliseconds
              99% <= 2000,02 milliseconds
            99.9% <= 2000,02 milliseconds

10.3.17 13:16:29 ===============================================================

-- Timers ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleTimer.timer
             count = 2
         mean rate = 0,33 calls/second
     1-minute rate = 0,40 calls/second
     5-minute rate = 0,40 calls/second
    15-minute rate = 0,40 calls/second
               min = 1000,19 milliseconds
               max = 2000,02 milliseconds
              mean = 1496,36 milliseconds
            stddev = 499,90 milliseconds
            median = 1000,19 milliseconds
              75% <= 2000,02 milliseconds
              95% <= 2000,02 milliseconds
              98% <= 2000,02 milliseconds
              99% <= 2000,02 milliseconds
            99.9% <= 2000,02 milliseconds

10.3.17 13:16:30 ===============================================================

-- Timers ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleTimer.timer
             count = 3
         mean rate = 0,42 calls/second
     1-minute rate = 0,40 calls/second
     5-minute rate = 0,40 calls/second
    15-minute rate = 0,40 calls/second
               min = 1000,19 milliseconds
               max = 3000,27 milliseconds
              mean = 2015,35 milliseconds
            stddev = 821,48 milliseconds
            median = 2000,02 milliseconds
              75% <= 3000,27 milliseconds
              95% <= 3000,27 milliseconds
              98% <= 3000,27 milliseconds
              99% <= 3000,27 milliseconds
            99.9% <= 3000,27 milliseconds

10.3.17 13:16:31 ===============================================================

-- Timers ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleTimer.timer
             count = 3
         mean rate = 0,37 calls/second
     1-minute rate = 0,40 calls/second
     5-minute rate = 0,40 calls/second
    15-minute rate = 0,40 calls/second
               min = 1000,19 milliseconds
               max = 3000,27 milliseconds
              mean = 2015,35 milliseconds
            stddev = 821,48 milliseconds
            median = 2000,02 milliseconds
              75% <= 3000,27 milliseconds
              95% <= 3000,27 milliseconds
              98% <= 3000,27 milliseconds
              99% <= 3000,27 milliseconds
            99.9% <= 3000,27 milliseconds

10.3.17 13:16:32 ===============================================================

-- Timers ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleTimer.timer
             count = 3
         mean rate = 0,33 calls/second
     1-minute rate = 0,40 calls/second
     5-minute rate = 0,40 calls/second
    15-minute rate = 0,40 calls/second
               min = 1000,19 milliseconds
               max = 3000,27 milliseconds
              mean = 2015,35 milliseconds
            stddev = 821,48 milliseconds
            median = 2000,02 milliseconds
              75% <= 3000,27 milliseconds
              95% <= 3000,27 milliseconds
              98% <= 3000,27 milliseconds
              99% <= 3000,27 milliseconds
            99.9% <= 3000,27 milliseconds

10.3.17 13:16:33 ===============================================================

-- Timers ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleTimer.timer
             count = 3
         mean rate = 0,30 calls/second
     1-minute rate = 0,38 calls/second
     5-minute rate = 0,40 calls/second
    15-minute rate = 0,40 calls/second
               min = 1000,19 milliseconds
               max = 3000,27 milliseconds
              mean = 2015,35 milliseconds
            stddev = 821,48 milliseconds
            median = 2000,02 milliseconds
              75% <= 3000,27 milliseconds
              95% <= 3000,27 milliseconds
              98% <= 3000,27 milliseconds
              99% <= 3000,27 milliseconds
            99.9% <= 3000,27 milliseconds

10.3.17 13:16:34 ===============================================================

-- Timers ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleTimer.timer
             count = 4
         mean rate = 0,36 calls/second
     1-minute rate = 0,38 calls/second
     5-minute rate = 0,40 calls/second
    15-minute rate = 0,40 calls/second
               min = 1000,19 milliseconds
               max = 4000,64 milliseconds
              mean = 2547,74 milliseconds
            stddev = 1125,78 milliseconds
            median = 3000,27 milliseconds
              75% <= 4000,64 milliseconds
              95% <= 4000,64 milliseconds
              98% <= 4000,64 milliseconds
              99% <= 4000,64 milliseconds
            99.9% <= 4000,64 milliseconds

10.3.17 13:16:35 ===============================================================

-- Timers ----------------------------------------------------------------------
cz.cca.dropwizard.ExampleTimer.timer
             count = 5
         mean rate = 0,41 calls/second
     1-minute rate = 0,38 calls/second
     5-minute rate = 0,40 calls/second
    15-minute rate = 0,40 calls/second
               min = 1000,19 milliseconds
               max = 4000,64 milliseconds
              mean = 2216,76 milliseconds
            stddev = 1182,63 milliseconds
            median = 2000,02 milliseconds
              75% <= 3000,27 milliseconds
              95% <= 4000,64 milliseconds
              98% <= 4000,64 milliseconds
              99% <= 4000,64 milliseconds
            99.9% <= 4000,64 milliseconds
Z výpisu je např. vidět, že akce byla zavolána 5x, nejkratší doba trvání byla 1 [s], nejdelší doba trvání byla 4 [s], průměrná doba trvání 2,2 [s], průměrně volána 0,4 x za vteřinu, atd.

Typy reportů


Měřené metriky lze exportovat různými způsoby použitím vhodného reporteru (JMX, Console, CSV, SLF4J, ...).

JMX


S JmxReporter lze vystavit metriky jako JMX MBeans. Metriky lze pak prohlížet např. přes VisualVM nebo JConsole.
final JmxReporter reporter = JmxReporter.forRegistry(registry).build();
reporter.start();
Aby bylo možné reporty zobrazovat ve VisualVM, je potřeba nainstalovat plugin VisualVM-MBeans. To lze udělat přes menu Tools - Plugins. Dále vybrat záložku Available Plugins a na ní zaškrtnout VisualVM-MBeans (viz https://visualvm.java.net/mbeans_tab.html).
VisualVMInstallPlugin.png
Po instalaci pluginu ve VisualVM přibude záložka MBeans, ve které lze zobrazit mimo jiné i sledovanou metriku.
VisualVMDropWizardMetrics.png

Console

ConsoleReporter (jak už název napovídá) vypisuje všechny registrované metriky v pravidelných intervalech do konzole. Lze nastavit periodu vypisování.
final ConsoleReporter reporter = ConsoleReporter.forRegistry(registry)
                                                .convertRatesTo(TimeUnit.SECONDS)
                                                .convertDurationsTo(TimeUnit.MILLISECONDS)
                                                .build();
reporter.start(1, TimeUnit.MINUTES); // Report každou minutu

CSV

Rovněž je možné vypisovat reporty do CSV souboru.
final CsvReporter reporter = CsvReporter.forRegistry(registry)
                                        .formatFor(Locale.US)
                                        .convertRatesTo(TimeUnit.SECONDS)
                                        .convertDurationsTo(TimeUnit.MILLISECONDS)
                                        .build(new File("c:/temp/data/"));
reporter.start(1, TimeUnit.MINUTES); // Report každou minutu
Vznikne CSV soubor, jehož název odpovídá zvolenému pojmenování dané metriky, tj. např. cz.cca.dropwizard.ExampleTimer.timer.csv.

Obsah souboru může vypadat následovně:
t,count,max,mean,min,stddev,p50,p75,p95,p98,p99,p999,mean_rate,m1_rate,m5_rate,m15_rate,rate_unit,duration_unit
1489385125,0,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,calls/second,milliseconds
1489385126,1,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,0.000000,calls/second,milliseconds
1489385127,1,2000.069790,2000.069790,2000.069790,0.000000,2000.069790,2000.069790,2000.069790,2000.069790,2000.069790,2000.069790,0.330471,0.000000,0.000000,0.000000,calls/second,milliseconds
1489385128,2,2000.069790,1496.486751,1000.401087,499.820294,1000.401087,2000.069790,2000.069790,2000.069790,2000.069790,2000.069790,0.496665,0.000000,0.000000,0.000000,calls/second,milliseconds
1489385129,2,2000.069790,1496.486751,1000.401087,499.820294,1000.401087,2000.069790,2000.069790,2000.069790,2000.069790,2000.069790,0.397866,0.400000,0.400000,0.400000,calls/second,milliseconds
1489385130,2,2000.069790,1496.486751,1000.401087,499.820294,1000.401087,2000.069790,2000.069790,2000.069790,2000.069790,2000.069790,0.331849,0.400000,0.400000,0.400000,calls/second,milliseconds
1489385131,3,3000.798068,2015.615413,1000.401087,821.611470,2000.069790,3000.798068,3000.798068,3000.798068,3000.798068,3000.798068,0.426933,0.400000,0.400000,0.400000,calls/second,milliseconds
1489385132,3,3000.798068,2015.615413,1000.401087,821.611470,2000.069790,3000.798068,3000.798068,3000.798068,3000.798068,3000.798068,0.373794,0.400000,0.400000,0.400000,calls/second,milliseconds
1489385133,3,3000.798068,2015.615413,1000.401087,821.611470,2000.069790,3000.798068,3000.798068,3000.798068,3000.798068,3000.798068,0.332395,0.400000,0.400000,0.400000,calls/second,milliseconds
1489385134,3,3000.798068,2015.615413,1000.401087,821.611470,2000.069790,3000.798068,3000.798068,3000.798068,3000.798068,3000.798068,0.299224,0.384009,0.396694,0.398892,calls/second,milliseconds
1489385135,4,4000.068969,2547.781812,1000.401087,1125.556948,3000.798068,4000.068969,4000.068969,4000.068969,4000.068969,4000.068969,0.362779,0.384009,0.396694,0.398892,calls/second,milliseconds
1489385136,5,4000.068969,2216.593549,999.976189,1182.679305,2000.069790,3000.798068,4000.068969,4000.068969,4000.068969,4000.068969,0.415778,0.384009,0.396694,0.398892,calls/second,milliseconds
Zobrazení v Excelu:
DropWizardCsvReport.png

SLF4J


Další možností je vypisovat metriky do logu přes SLF4J logger.

final Slf4jReporter reporter = Slf4jReporter.forRegistry(registry)
                                            .outputTo(LoggerFactory.getLogger("cz.cca.example.metrics"))
                                            .convertRatesTo(TimeUnit.SECONDS)
                                            .convertDurationsTo(TimeUnit.MILLISECONDS)
                                            .build();
reporter.start(1, TimeUnit.MINUTES);  // Report každou minutu

Další možnosti reportů


Existují i další možnosti reportů, např.:

  • MetricsServlet (který poskytuje metriky jako objekt JSON)
  • GangliaReporter (umožňuje přenos metrik na servery Ganglia)
  • GraphiteReporter (umožňuje přenos metrik na servery Graphite)

Další možnosti reportů a integrace metrik do jiných systémů poskytují knihovny třetích stran (http://metrics.dropwizard.io/3.1.0/manual/third-party/).

Přístup k hodnotám metrik


Kromě toho, že je možné jednotlivé metriky vypisovat pomocí reportů, je rovněž možné pracovat přímo s jednotlivými hodnotami v aplikaci. Každá metrika poskytuje metody pro jejich získání.

Například hodnoty metriky Meter (viz níže)
-- Meters ----------------------------------------------------------------------
meter
             count = 33
         mean rate = 16,58 events/second
     1-minute rate = 0,00 events/second
     5-minute rate = 0,00 events/second
    15-minute rate = 0,00 events/second
můžeme získat voláním následujících funkcí
System.out.println("count = " + meter.getCount());
System.out.println("mean rate = " + meter.getMeanRate());
System.out.println("1-minute rate = " + meter.getOneMinuteRate());
System.out.println("5-minute rate = " + meter.getFiveMinuteRate());
System.out.println("15-minute rate = " + meter.getFifteenMinuteRate());
Stejným způsobem lze získat jakékoliv hodnoty všech poskytovaných metrik a dále je zpracovávat/vypisovat/vykreslovat z nich grafy apod. Vracené hodnoty jsou samozřejmě proměnlivé v čase.

Autor článku: Ondřej Čabrada, CCA Group a.s.

Žádné komentáře:

Okomentovat