From e7ea1521acfd9fe26525db534e989c075dd74c3b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lu=C3=ADs=20Serralheiro?= Date: Sat, 25 May 2024 15:42:55 +0100 Subject: [PATCH 1/7] Adding service level objectives support to the @Timed annotation --- .../main/java/io/micrometer/core/annotation/Timed.java | 9 +++++++++ .../main/java/io/micrometer/core/aop/TimedAspect.java | 9 ++++++++- .../main/java/io/micrometer/core/instrument/Timer.java | 8 +++++++- 3 files changed, 24 insertions(+), 2 deletions(-) diff --git a/micrometer-core/src/main/java/io/micrometer/core/annotation/Timed.java b/micrometer-core/src/main/java/io/micrometer/core/annotation/Timed.java index da75034002..fc62d882a3 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/annotation/Timed.java +++ b/micrometer-core/src/main/java/io/micrometer/core/annotation/Timed.java @@ -74,6 +74,15 @@ */ boolean histogram() default false; + /** + * List of service level objectives to calculate client-side for the + * {@link io.micrometer.core.instrument.Timer} in seconds. For example, for a 100ms + * should be passed as {@code 0.1}. + * @return service level objectives to calculate + * @see io.micrometer.core.instrument.Timer.Builder#serviceLevelObjectives(java.time.Duration...) + */ + double[] serviceLevelObjectives() default {}; + /** * Description of the {@link io.micrometer.core.instrument.Timer}. * @return meter description diff --git a/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java b/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java index 313da42f53..6952d646c7 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java +++ b/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java @@ -20,14 +20,18 @@ import io.micrometer.core.annotation.Incubating; import io.micrometer.core.annotation.Timed; import io.micrometer.core.instrument.*; +import io.micrometer.core.instrument.util.TimeUtils; import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.Around; import org.aspectj.lang.annotation.Aspect; import org.aspectj.lang.reflect.MethodSignature; import java.lang.reflect.Method; +import java.time.Duration; +import java.util.Arrays; import java.util.Optional; import java.util.concurrent.CompletionStage; +import java.util.concurrent.TimeUnit; import java.util.function.Function; import java.util.function.Predicate; @@ -254,7 +258,10 @@ private Timer.Builder recordBuilder(ProceedingJoinPoint pjp, Timed timed, String .tags(EXCEPTION_TAG, exceptionClass) .tags(tagsBasedOnJoinPoint.apply(pjp)) .publishPercentileHistogram(timed.histogram()) - .publishPercentiles(timed.percentiles().length == 0 ? null : timed.percentiles()); + .serviceLevelObjectives((Duration[]) Arrays.stream(timed.serviceLevelObjectives()) + .mapToObj(s -> Duration.ofNanos((long) TimeUtils.secondsToUnit(s, TimeUnit.NANOSECONDS))) + .toArray()); + if (meterTagAnnotationHandler != null) { meterTagAnnotationHandler.addAnnotatedParameters(builder, pjp); } diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java index f7e8e475b9..e45934d458 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java +++ b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java @@ -22,9 +22,12 @@ import io.micrometer.core.instrument.distribution.HistogramSupport; import io.micrometer.core.instrument.distribution.ValueAtPercentile; import io.micrometer.core.instrument.distribution.pause.PauseDetector; +import io.micrometer.core.instrument.util.TimeUtils; import java.time.Duration; +import java.util.ArrayList; import java.util.Arrays; +import java.util.List; import java.util.concurrent.Callable; import java.util.concurrent.TimeUnit; import java.util.function.*; @@ -100,7 +103,10 @@ static Builder builder(Timed timed, String defaultName) { return new Builder(timed.value().isEmpty() ? defaultName : timed.value()).tags(timed.extraTags()) .description(timed.description().isEmpty() ? null : timed.description()) .publishPercentileHistogram(timed.histogram()) - .publishPercentiles(timed.percentiles().length > 0 ? timed.percentiles() : null); + .publishPercentiles(timed.percentiles().length > 0 ? timed.percentiles() : null) + .serviceLevelObjectives((Duration[]) Arrays.stream(timed.serviceLevelObjectives()) + .mapToObj(s -> Duration.ofNanos((long) TimeUtils.secondsToUnit(s, TimeUnit.NANOSECONDS))) + .toArray()); } /** From 9a840e9004afbb9e00dccdee798bf27a5966ac0f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lu=C3=ADs=20Serralheiro?= Date: Sun, 26 May 2024 12:49:20 +0100 Subject: [PATCH 2/7] Style fixes --- .../src/main/java/io/micrometer/core/instrument/Timer.java | 2 -- 1 file changed, 2 deletions(-) diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java index e45934d458..ec87c25c45 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java +++ b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java @@ -25,9 +25,7 @@ import io.micrometer.core.instrument.util.TimeUtils; import java.time.Duration; -import java.util.ArrayList; import java.util.Arrays; -import java.util.List; import java.util.concurrent.Callable; import java.util.concurrent.TimeUnit; import java.util.function.*; From 1485ba11e1e32a89ba0951d4821d45cb6f13c5df Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lu=C3=ADs=20Serralheiro?= Date: Mon, 8 Jul 2024 10:57:45 +0100 Subject: [PATCH 3/7] Fixing broken tests --- .../main/java/io/micrometer/core/aop/TimedAspect.java | 9 ++++++--- .../main/java/io/micrometer/core/instrument/Timer.java | 9 ++++++--- 2 files changed, 12 insertions(+), 6 deletions(-) diff --git a/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java b/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java index 6952d646c7..92f7c4716f 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java +++ b/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java @@ -258,9 +258,12 @@ private Timer.Builder recordBuilder(ProceedingJoinPoint pjp, Timed timed, String .tags(EXCEPTION_TAG, exceptionClass) .tags(tagsBasedOnJoinPoint.apply(pjp)) .publishPercentileHistogram(timed.histogram()) - .serviceLevelObjectives((Duration[]) Arrays.stream(timed.serviceLevelObjectives()) - .mapToObj(s -> Duration.ofNanos((long) TimeUtils.secondsToUnit(s, TimeUnit.NANOSECONDS))) - .toArray()); + .serviceLevelObjectives(timed.serviceLevelObjectives().length > 0 ? + (Duration[]) Arrays.stream(timed.serviceLevelObjectives()) + .mapToObj(s -> Duration.ofNanos((long) TimeUtils.secondsToUnit(s, TimeUnit.NANOSECONDS))) + .toArray() + : null + ); if (meterTagAnnotationHandler != null) { meterTagAnnotationHandler.addAnnotatedParameters(builder, pjp); diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java index ec87c25c45..9ba7bb5796 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java +++ b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java @@ -102,9 +102,12 @@ static Builder builder(Timed timed, String defaultName) { .description(timed.description().isEmpty() ? null : timed.description()) .publishPercentileHistogram(timed.histogram()) .publishPercentiles(timed.percentiles().length > 0 ? timed.percentiles() : null) - .serviceLevelObjectives((Duration[]) Arrays.stream(timed.serviceLevelObjectives()) - .mapToObj(s -> Duration.ofNanos((long) TimeUtils.secondsToUnit(s, TimeUnit.NANOSECONDS))) - .toArray()); + .serviceLevelObjectives(timed.serviceLevelObjectives().length > 0 ? + (Duration[]) Arrays.stream(timed.serviceLevelObjectives()) + .mapToObj(s -> Duration.ofNanos((long) TimeUtils.secondsToUnit(s, TimeUnit.NANOSECONDS))) + .toArray() + : null + ); } /** From 884bcbdf9b3a0302834bbf372d33076e0df72ef1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lu=C3=ADs=20Serralheiro?= Date: Mon, 8 Jul 2024 11:03:34 +0100 Subject: [PATCH 4/7] Making it pretty --- .../main/java/io/micrometer/core/aop/TimedAspect.java | 11 +++++------ .../java/io/micrometer/core/instrument/Timer.java | 11 +++++------ 2 files changed, 10 insertions(+), 12 deletions(-) diff --git a/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java b/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java index 92f7c4716f..f08e4d1d80 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java +++ b/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java @@ -258,12 +258,11 @@ private Timer.Builder recordBuilder(ProceedingJoinPoint pjp, Timed timed, String .tags(EXCEPTION_TAG, exceptionClass) .tags(tagsBasedOnJoinPoint.apply(pjp)) .publishPercentileHistogram(timed.histogram()) - .serviceLevelObjectives(timed.serviceLevelObjectives().length > 0 ? - (Duration[]) Arrays.stream(timed.serviceLevelObjectives()) - .mapToObj(s -> Duration.ofNanos((long) TimeUtils.secondsToUnit(s, TimeUnit.NANOSECONDS))) - .toArray() - : null - ); + .serviceLevelObjectives(timed.serviceLevelObjectives().length > 0 + ? (Duration[]) Arrays.stream(timed.serviceLevelObjectives()) + .mapToObj(s -> Duration.ofNanos((long) TimeUtils.secondsToUnit(s, TimeUnit.NANOSECONDS))) + .toArray() + : null); if (meterTagAnnotationHandler != null) { meterTagAnnotationHandler.addAnnotatedParameters(builder, pjp); diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java index 9ba7bb5796..c8a33d170e 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java +++ b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java @@ -102,12 +102,11 @@ static Builder builder(Timed timed, String defaultName) { .description(timed.description().isEmpty() ? null : timed.description()) .publishPercentileHistogram(timed.histogram()) .publishPercentiles(timed.percentiles().length > 0 ? timed.percentiles() : null) - .serviceLevelObjectives(timed.serviceLevelObjectives().length > 0 ? - (Duration[]) Arrays.stream(timed.serviceLevelObjectives()) - .mapToObj(s -> Duration.ofNanos((long) TimeUtils.secondsToUnit(s, TimeUnit.NANOSECONDS))) - .toArray() - : null - ); + .serviceLevelObjectives(timed.serviceLevelObjectives().length > 0 + ? (Duration[]) Arrays.stream(timed.serviceLevelObjectives()) + .mapToObj(s -> Duration.ofNanos((long) TimeUtils.secondsToUnit(s, TimeUnit.NANOSECONDS))) + .toArray() + : null); } /** From 1704e450f3aa1e7f5a0f5b201bcbd99257be0a22 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lu=C3=ADs=20Serralheiro?= Date: Mon, 8 Jul 2024 12:08:07 +0100 Subject: [PATCH 5/7] Adding test for the TimedAspect --- .../io/micrometer/core/aop/TimedAspect.java | 9 +++--- .../io/micrometer/core/instrument/Timer.java | 7 ++--- .../micrometer/core/aop/TimedAspectTest.java | 30 +++++++++++++++++++ 3 files changed, 37 insertions(+), 9 deletions(-) diff --git a/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java b/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java index f08e4d1d80..7f9085900e 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java +++ b/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java @@ -246,7 +246,7 @@ private void record(ProceedingJoinPoint pjp, Timed timed, String metricName, Tim sample.stop(recordBuilder(pjp, timed, metricName, exceptionClass).register(registry)); } catch (Exception e) { - // ignoring on purpose + System.out.println(e);// ignoring on purpose } } @@ -258,11 +258,10 @@ private Timer.Builder recordBuilder(ProceedingJoinPoint pjp, Timed timed, String .tags(EXCEPTION_TAG, exceptionClass) .tags(tagsBasedOnJoinPoint.apply(pjp)) .publishPercentileHistogram(timed.histogram()) - .serviceLevelObjectives(timed.serviceLevelObjectives().length > 0 - ? (Duration[]) Arrays.stream(timed.serviceLevelObjectives()) + .serviceLevelObjectives( + timed.serviceLevelObjectives().length > 0 ? Arrays.stream(timed.serviceLevelObjectives()) .mapToObj(s -> Duration.ofNanos((long) TimeUtils.secondsToUnit(s, TimeUnit.NANOSECONDS))) - .toArray() - : null); + .toArray(Duration[]::new) : null); if (meterTagAnnotationHandler != null) { meterTagAnnotationHandler.addAnnotatedParameters(builder, pjp); diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java index c8a33d170e..02c2d6c4d8 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java +++ b/micrometer-core/src/main/java/io/micrometer/core/instrument/Timer.java @@ -102,11 +102,10 @@ static Builder builder(Timed timed, String defaultName) { .description(timed.description().isEmpty() ? null : timed.description()) .publishPercentileHistogram(timed.histogram()) .publishPercentiles(timed.percentiles().length > 0 ? timed.percentiles() : null) - .serviceLevelObjectives(timed.serviceLevelObjectives().length > 0 - ? (Duration[]) Arrays.stream(timed.serviceLevelObjectives()) + .serviceLevelObjectives( + timed.serviceLevelObjectives().length > 0 ? Arrays.stream(timed.serviceLevelObjectives()) .mapToObj(s -> Duration.ofNanos((long) TimeUtils.secondsToUnit(s, TimeUnit.NANOSECONDS))) - .toArray() - : null); + .toArray(Duration[]::new) : null); } /** diff --git a/micrometer-core/src/test/java/io/micrometer/core/aop/TimedAspectTest.java b/micrometer-core/src/test/java/io/micrometer/core/aop/TimedAspectTest.java index a44bda8927..592d890860 100644 --- a/micrometer-core/src/test/java/io/micrometer/core/aop/TimedAspectTest.java +++ b/micrometer-core/src/test/java/io/micrometer/core/aop/TimedAspectTest.java @@ -23,6 +23,7 @@ import io.micrometer.core.instrument.Meter.Id; import io.micrometer.core.instrument.MeterRegistry; import io.micrometer.core.instrument.Timer; +import io.micrometer.core.instrument.distribution.CountAtBucket; import io.micrometer.core.instrument.distribution.DistributionStatisticConfig; import io.micrometer.core.instrument.distribution.pause.PauseDetector; import io.micrometer.core.instrument.search.MeterNotFoundException; @@ -34,6 +35,7 @@ import org.springframework.aop.aspectj.annotation.AspectJProxyFactory; import javax.annotation.Nonnull; +import java.util.Arrays; import java.util.concurrent.CompletableFuture; import java.util.concurrent.CompletionException; import java.util.function.Predicate; @@ -95,6 +97,29 @@ void timeMethodWithLongTaskTimer() { .size()).isEqualTo(1); } + @Test + void timeMethodWithSloTimer() { + MeterRegistry registry = new SimpleMeterRegistry(); + + AspectJProxyFactory pf = new AspectJProxyFactory(new TimedService()); + pf.addAspect(new TimedAspect(registry)); + + TimedService service = pf.getProxy(); + + service.sloCall(); + + assertThat(Arrays + .stream(registry.get("sloCall") + .tag("class", getClass().getName() + "$TimedService") + .tag("method", "sloCall") + .tag("extra", "tag") + .timer() + .takeSnapshot() + .histogramCounts()) + .mapToDouble(CountAtBucket::bucket) + .toArray()).isEqualTo(new double[] { Math.pow(10, 9) * 0.1, Math.pow(10, 9) * 0.5 }); + } + @Test void timeMethodFailure() { MeterRegistry failingRegistry = new FailingMeterRegistry(); @@ -621,6 +646,11 @@ void call() { void longCall() { } + @Timed(value = "sloCall", extraTags = { "extra", "tag" }, histogram = true, + serviceLevelObjectives = { 0.1, 0.5 }) + void sloCall() { + } + } static class AsyncTimedService { From fca334fb9d64156c1e21c70ad42ebcce2a320c9b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lu=C3=ADs=20Serralheiro?= Date: Mon, 8 Jul 2024 12:15:21 +0100 Subject: [PATCH 6/7] Cleaning up from debugging --- .../src/main/java/io/micrometer/core/aop/TimedAspect.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java b/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java index 7f9085900e..cc3dd33d56 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java +++ b/micrometer-core/src/main/java/io/micrometer/core/aop/TimedAspect.java @@ -246,7 +246,7 @@ private void record(ProceedingJoinPoint pjp, Timed timed, String metricName, Tim sample.stop(recordBuilder(pjp, timed, metricName, exceptionClass).register(registry)); } catch (Exception e) { - System.out.println(e);// ignoring on purpose + // ignoring on purpose } } From 51d3a0f58402d509cd069d139892211f2be50f37 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lu=C3=ADs=20Serralheiro?= Date: Mon, 8 Jul 2024 12:35:27 +0100 Subject: [PATCH 7/7] Adding test for the builder --- .../MetricsRequestEventListenerTimedTest.java | 15 +++++++++++++++ .../jersey/server/resources/TimedResource.java | 7 +++++++ 2 files changed, 22 insertions(+) diff --git a/micrometer-core/src/test/java/io/micrometer/core/instrument/binder/jersey/server/MetricsRequestEventListenerTimedTest.java b/micrometer-core/src/test/java/io/micrometer/core/instrument/binder/jersey/server/MetricsRequestEventListenerTimedTest.java index b9c3207c5a..fa55243a97 100644 --- a/micrometer-core/src/test/java/io/micrometer/core/instrument/binder/jersey/server/MetricsRequestEventListenerTimedTest.java +++ b/micrometer-core/src/test/java/io/micrometer/core/instrument/binder/jersey/server/MetricsRequestEventListenerTimedTest.java @@ -21,6 +21,7 @@ import io.micrometer.core.instrument.Tags; import io.micrometer.core.instrument.binder.jersey.server.resources.TimedOnClassResource; import io.micrometer.core.instrument.binder.jersey.server.resources.TimedResource; +import io.micrometer.core.instrument.distribution.CountAtBucket; import io.micrometer.core.instrument.simple.SimpleMeterRegistry; import org.glassfish.jersey.server.ResourceConfig; import org.glassfish.jersey.test.JerseyTest; @@ -93,6 +94,20 @@ void resourcesWithAnnotationAreTimed() { assertThat(registry.get("multi2").tags(tagsFrom("/multi-timed", 200)).timer().count()).isEqualTo(1); } + @Test + void sloTaskTimerSupported() throws InterruptedException, ExecutionException, TimeoutException { + target("timed-slo").request().get(); + + CountAtBucket[] slos = registry.get("timedSlo") + .tags(tagsFrom("/timed-slo", 200)) + .timer() + .takeSnapshot() + .histogramCounts(); + assertThat(slos.length).isEqualTo(2); + assertThat(slos[0].bucket()).isEqualTo(Math.pow(10, 9) * 0.1); + assertThat(slos[1].bucket()).isEqualTo(Math.pow(10, 9) * 0.5); + } + @Test void longTaskTimerSupported() throws InterruptedException, ExecutionException, TimeoutException { final Future future = target("long-timed").request().async().get(); diff --git a/micrometer-core/src/test/java/io/micrometer/core/instrument/binder/jersey/server/resources/TimedResource.java b/micrometer-core/src/test/java/io/micrometer/core/instrument/binder/jersey/server/resources/TimedResource.java index 9777c22126..83e97968dc 100644 --- a/micrometer-core/src/test/java/io/micrometer/core/instrument/binder/jersey/server/resources/TimedResource.java +++ b/micrometer-core/src/test/java/io/micrometer/core/instrument/binder/jersey/server/resources/TimedResource.java @@ -54,6 +54,13 @@ public String timed() { return "timed"; } + @GET + @Path("timed-slo") + @Timed(value = "timedSlo", histogram = true, serviceLevelObjectives = { 0.1, 0.5 }) + public String timedSlo() { + return "timed"; + } + @GET @Path("multi-timed") @Timed("multi1")