Skip to content

Commit 5bb01dd

Browse files
rbygraverbygrave
committed
Update README
1 parent 00db010 commit 5bb01dd

File tree

1 file changed

+118
-54
lines changed

1 file changed

+118
-54
lines changed

‎README.md‎

Lines changed: 118 additions & 54 deletions
Original file line numberDiff line numberDiff line change
@@ -6,74 +6,138 @@ Please read the main documentation at: http://avaje-metrics.github.io
66

77
```xml
88
<dependency>
9-
<groupId>org.avaje.metric</groupId>
10-
<artifactId>avaje-metric-core</artifactId>
11-
<version>4.4.1</version>
9+
<groupId>io.avaje</groupId>
10+
<artifactId>avaje-metrics</artifactId>
11+
<version>9.2</version>
1212
</dependency>
1313
```
1414

1515

1616
## License - Apache 2
1717
Published under Apache Software License 2.0, see LICENSE
1818

19-
## Overhead
20-
Micro benchmarks are notoriously difficult but that said the overhead using version 4.1 has been measured at 140 nanos per method invocation (with request collection count of 0 meaning per request timing isn't collected). For perspective if the overhead was 200 nanos then executing 5000 methods would add 1 millisecond of overhead.
21-
22-
Request timing would not add much more to execution time per say but relatively speaking can produce a lot of output (that is reported in a background thread) and creates objects so adds some extra GC cost. In production you would expect to limit the number of metrics you collect on and limit the number of request timings you collect.
23-
24-
## Example Metrics output (typically reported every 60 seconds)
25-
Below is a sample of the metric log output. The metrics are periodically collected
26-
and output to a file or sent to a repository.
27-
28-
```console
29-
14:01:00, lg, jvm.gc.ps-marksweep, count=0, time=0
30-
14:01:00, lg, jvm.gc.ps-scavenge, count=0, time=0
31-
14:01:00, dg, jvm.memory.heap, init=250.2, used=64.59, committed=240.0, max=3559.0, pct=1.0
32-
14:01:00, dg, jvm.memory.nonheap, init=23.44, used=20.67, committed=23.44, max=214.0, pct=9.0
33-
14:01:00, dm, jvm.os.loadAverage, value=1.06
34-
14:01:00, dm, jvm.system.uptime, value=5.0
35-
14:01:00, lg, jvm.threads, current=17, peak=18, daemon=5
36-
14:01:00, tm, org.example.myapp.service.DummyEmailSender.send, count=1, avg=140, max=140, sum=140, dur=10, err.count=0
37-
14:01:00, tm, org.example.myapp.service.DummyEmailSender.yeahNah, count=1, avg=128, max=128, sum=128, dur=10, err.count=0
38-
14:01:00, tm, org.example.myapp.service.Muse.iDoTheRealWorkAroundHere, count=1, avg=500084, max=500084, sum=500084, dur=10, err.count=0
39-
14:01:00, tm, org.example.myapp.service.Muse.notParticularlyResistant, count=1, avg=2, max=2, sum=2, dur=10, err.count=0
40-
14:01:00, tm, org.example.myapp.service.Muse.notThatResistant, count=1, avg=4, max=4, sum=4, dur=10, err.count=0
41-
14:01:00, tm, org.example.myapp.service.Muse.originOfSymmetry, count=1, avg=1075, max=1075, sum=1075, dur=10, err.count=0
42-
14:01:00, tm, org.example.myapp.service.Muse.resistance, count=1, avg=500157, max=500157, sum=500157, dur=10, err.count=0
43-
14:01:00, tm, org.example.myapp.service.MusicLayer.playItSon, count=1, avg=611869, max=611869, sum=611869, dur=10, err.count=0
44-
14:01:00, tm, org.example.myapp.service.RadioHead.kidA, count=1, avg=51234, max=51234, sum=51234, dur=10, err.count=0
45-
14:01:00, tm, org.example.myapp.service.RadioHead.pabloHoney, count=1, avg=550258, max=550258, sum=550258, dur=10, err.count=0
46-
14:01:00, tm, org.example.myapp.service.RadioHead.theBends, count=1, avg=560440, max=560440, sum=560440, dur=10, err.count=0
47-
14:01:00, tm, org.example.myapp.web.api.CustomerResource.asBean, count=1, avg=612154, max=612154, sum=612154, dur=10, err.count=0
48-
14:01:00, tm, org.example.myapp.web.api.CustomerResource.hello, count=1, avg=284, max=284, sum=284, dur=10, err.count=0
49-
14:01:00, tm, org.example.myapp.web.api.MetricResource.collecting, count=1, avg=382, max=382, sum=382, dur=10, err.count=0
19+
## MetricRegistry
20+
21+
A MetricRegistry holds the metrics like timers, gauges etc.
22+
23+
```java
24+
MetricRegistry registry = Metrics.createRegistry();
25+
26+
// obtain timers, counters, gauges etc
27+
Timer timer = registry.timer("my.timer");
28+
Counter counter = registry.counter("my.count");
29+
```
30+
31+
## Metrics & default registry
32+
33+
There is default MetricRegistry. Creating metrics via `Metrics` creates metrics attached to the default registry.
34+
35+
```java
36+
// obtain the default MetricRegistry
37+
MetricRegistry defaultRegistry = Metrics.registry();
38+
```
39+
40+
```java
41+
// timer registered with the default MetricRegistry
42+
Timer timer = Metrics.timer("my.timer");
43+
```
44+
45+
## Counter
46+
47+
A Counter holds a single long value that is incremented
48+
49+
```java
50+
Counter counter = registry.counter("my.count");
51+
52+
counter.inc();
53+
counter.inc(42);
54+
```
55+
56+
## Meter
57+
58+
A Meter is used to represent events that have a value such as bytes sent, bytes received, lines read etc.
59+
60+
```java
61+
Meter meter = registry.meter("my.meter");
62+
63+
meter.addEvent(42);
64+
meter.addEvent(44);
65+
meter.addEvent(46);
66+
```
67+
68+
## Gauge
69+
70+
Gauges are used to measure something that supplies a value. Creating a Gauge takes either a LongSupplier or a DoubleSupplier.
71+
72+
Gauges are used for JVM Memory metrics and Garbage collection. Although application can obtain values from a Gauge typically
73+
we register the gauge and the value is obtained when the metrics are reported.
74+
75+
```java
76+
registry.gauge("my.gauge0", myLongSupplier );
77+
registry.gauge("my.gauge1", myDoubleSupplier );
5078
```
5179

52-
## Example Per Request output
80+
There are `incrementing` wrappers that can be applied to the LongSupplier of DoubleSupplier to use for the case
81+
when the gauge only increments and we wish to report the change.
82+
83+
```java
84+
// wrap via incrementing()
85+
GaugeLong myIncrementing = GaugeLong.incrementing(myLongSupplier);
86+
87+
registry.gauge("my.gauge", myIncrementing);
88+
```
5389

54-
> Per Request timing is a little bit more expensive to collect and can produce a lot of output. As such it is expected that you only turn it on when needed. For example, for the next 5 invocations of CustomerResource.asBean() collect per request timings.
90+
## Timer
5591

56-
Per request timing can be set for specific timing metrics - for example, collect per request timing on the next 5 invocations of the CustomerResource.asBean() method.
92+
A Timer measures the time on an event in microseconds.
93+
It provides count, total time in micros, mean time in micros, max time in micros.
5794

58-
Per request timing output shows the nested calls and where the time went for that single request. The p column shows the percentage of total execution - for example 81% of execution time was taken in Muse.iDoTheRealWorkAroundHere. Typically in looking at this output you ignore/remove/collapse anything that has percentage of 0.
95+
Timers can be obtained and used via code or via `@Timed` enhancement. We can also
96+
apply timers on "All non-private methods of Spring Beans"
97+
or "All non-private methods of Avaje Inject Beans"
5998

60-
The columns are: d=depth, p=percentage, ms=milliseconds, us=microseconds, m=metric name
99+
#### @Timed
61100

62-
```console
63-
14:00:20 exe:612ms metric:org.example.myapp.web.api.CustomerResource.asBean
64-
d:0 p:100 ms:612 us:612091 m:org.example.myapp.web.api.CustomerResource.asBean
65-
d:1 p:99 ms:611 us:611886 m:org.example.myapp.service.MusicLayer.playItSon
66-
d:2 p:0 ms:0 us:125 m:org.example.myapp.service.DummyEmailSender.send
67-
d:3 p:0 ms:0 us:106 m:org.example.myapp.service.DummyEmailSender.yeahNah
68-
d:2 p:8 ms:51 us:51179 m:org.example.myapp.service.RadioHead.kidA
69-
d:3 p:0 ms:1 us:1072 m:org.example.myapp.service.Muse.originOfSymmetry
70-
d:2 p:91 ms:560 us:560546 m:org.example.myapp.service.RadioHead.theBends
71-
d:3 p:89 ms:550 us:550377 m:org.example.myapp.service.RadioHead.pabloHoney
72-
d:4 p:81 ms:500 us:500204 m:org.example.myapp.service.Muse.resistance
73-
d:5 p:0 ms:0 us:33 m:org.example.myapp.service.Muse.notThatResistant
74-
d:5 p:81 ms:500 us:500108 m:org.example.myapp.service.Muse.iDoTheRealWorkAroundHere
75-
d:5 p:0 ms:0 us:11 m:org.example.myapp.service.Muse.notParticularlyResistant
101+
Timers can be added by putting `@Timed` on a class. Then enhancement will add timers to
102+
all non-private methods on that class. We use `@NotTimed` to not have a method timed.
103+
104+
105+
#### Using Timer programmatically
106+
107+
Obtain a Timer from the `MetricRegistry` or via `Metrics.timer(...)` which uses the default registry.
108+
109+
```java
110+
Timer metric = Metrics.timer("test.runnable");
76111
```
77-
CustomerResource.asBean took 612 milliseconds to execute. If you look at Muse.iDoTheRealWorkAroundHere it took 81% of the total execution time (500 milliseconds, 500204 microseconds).
78112

113+
#### Time Runnable
114+
115+
The Timer can take a runnable like:
116+
117+
```java
118+
Timer timer = Metrics.timer("test.runnable");
119+
120+
// using runnable
121+
timer.time( //* ... runnable */ );
122+
```
123+
124+
#### Time using start nanos
125+
```java
126+
long startNanos = System.nanoTime();
127+
128+
// do something we want to time ...
129+
timer.add(startNanos);
130+
```
131+
This is an efficient way to time events with no extra object allocation.
132+
133+
The time is the difference between startNanos and when that is added to
134+
the timer.
135+
136+
137+
#### Time using startEvent
138+
```java
139+
Event event = timer.startEvent();
140+
// do something we want to time ...
141+
event.end();
142+
```
79143

0 commit comments

Comments
 (0)