Implement @scheduled timing, changed record -> recordThrowable in Tim…

…er, Gradle 4.0

gradle/wrapper/gradle-wrapper.properties

@@ -1,6 +1,6 @@
-#Mon Apr 10 14:49:12 CDT 2017
+#Thu May 18 12:01:02 CDT 2017
 distributionBase=GRADLE_USER_HOME
 distributionPath=wrapper/dists
 zipStoreBase=GRADLE_USER_HOME
 zipStorePath=wrapper/dists
-distributionUrl=https\://services.gradle.org/distributions/gradle-3.0-all.zip
+distributionUrl=https\://services.gradle.org/distributions/gradle-4.0-milestone-2-bin.zip

gradlew

@@ -1,4 +1,4 @@
-#!/usr/bin/env sh
+#!/usr/bin/env bash
 
 ##############################################################################
 ##
@@ -154,19 +154,16 @@ if $cygwin ; then
     esac
 fi
 
-# Escape application args
-save ( ) {
-    for i do printf %s\\n "$i" | sed "s/'/'\\\\''/g;1s/^/'/;\$s/\$/' \\\\/" ; done
-    echo " "
+# Split up the JVM_OPTS And GRADLE_OPTS values into an array, following the shell quoting and substitution rules
+function splitJvmOpts() {
+    JVM_OPTS=("$@")
 }
-APP_ARGS=$(save "$@")
-
-# Collect all arguments for the java command, following the shell quoting and substitution rules
-eval set -- $DEFAULT_JVM_OPTS $JAVA_OPTS $GRADLE_OPTS "\"-Dorg.gradle.appname=$APP_BASE_NAME\"" -classpath "\"$CLASSPATH\"" org.gradle.wrapper.GradleWrapperMain "$APP_ARGS"
+eval splitJvmOpts $DEFAULT_JVM_OPTS $JAVA_OPTS $GRADLE_OPTS
+JVM_OPTS[${#JVM_OPTS[*]}]="-Dorg.gradle.appname=$APP_BASE_NAME"
 
 # by default we should be in the correct project dir, but when run from Finder on Mac, the cwd is wrong
-if [ "$(uname)" = "Darwin" ] && [ "$HOME" = "$PWD" ]; then
+if [[ "$(uname)" == "Darwin" ]] && [[ "$HOME" == "$PWD" ]]; then
   cd "$(dirname "$0")"
 fi
 
-exec "$JAVACMD" "$@"
+exec "$JAVACMD" "${JVM_OPTS[@]}" -classpath "$CLASSPATH" org.gradle.wrapper.GradleWrapperMain "$@"

src/main/java/org/springframework/metrics/boot/EnableMetricsBoot1.java

@@ -32,6 +32,7 @@
 import org.springframework.core.env.Environment;
 import org.springframework.http.client.ClientHttpRequestInterceptor;
 import org.springframework.metrics.instrument.MeterRegistry;
+import org.springframework.metrics.instrument.scheduling.MetricsSchedulingAspect;
 import org.springframework.metrics.instrument.web.*;
 import org.springframework.web.client.RestTemplate;
 import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
@@ -40,6 +41,7 @@
 import javax.servlet.http.HttpServletRequest;
 import java.lang.annotation.*;
 import java.util.ArrayList;
+import java.util.regex.Pattern;
 
 /**
  * Enable dimensional metrics collection.
@@ -109,6 +111,16 @@ public WebMetricsTagProvider emptyMetricsTagProvider() {
         }
     }
 
+    /**
+     * If AOP is not enabled, scheduled interception will not work.
+     */
+    @Bean
+    @ConditionalOnClass({RestTemplate.class, JoinPoint.class})
+    @ConditionalOnProperty(value = "spring.aop.enabled", havingValue = "true", matchIfMissing = true)
+    public MetricsSchedulingAspect metricsSchedulingAspect(MeterRegistry registry) {
+        return new MetricsSchedulingAspect(registry);
+    }
+
     /**
      * If AOP is not enabled, client request interception will still work, but the URI tag
      * will always be evaluated to "none".

src/main/java/org/springframework/metrics/instrument/ThrowableCallable.java

@@ -0,0 +1,12 @@
+package org.springframework.metrics.instrument;
+
+@FunctionalInterface
+public interface ThrowableCallable<V> {
+    /**
+     * Computes a result, or throws an exception if unable to do so.
+     *
+     * @return computed result
+     * @throws Throwable if unable to compute a result
+     */
+    V call() throws Throwable;
+}

src/main/java/org/springframework/metrics/instrument/Timer.java

@@ -39,7 +39,7 @@ public interface Timer extends Meter {
      * @param f Function to execute and measure the execution time.
      * @return The return value of `f`.
      */
-    <T> T record(Callable<T> f) throws MetricException;
+    <T> T recordThrowable(ThrowableCallable<T> f) throws Throwable;
 
     /**
      * Executes the runnable `f` and records the time taken.

src/main/java/org/springframework/metrics/instrument/internal/AbstractTimer.java

@@ -16,10 +16,9 @@
 package org.springframework.metrics.instrument.internal;
 
 import org.springframework.metrics.instrument.Clock;
-import org.springframework.metrics.instrument.MetricException;
+import org.springframework.metrics.instrument.ThrowableCallable;
 import org.springframework.metrics.instrument.Timer;
 
-import java.util.concurrent.Callable;
 import java.util.concurrent.TimeUnit;
 
 public abstract class AbstractTimer implements Timer {
@@ -32,12 +31,10 @@ protected AbstractTimer(String name, Clock clock) {
     }
 
     @Override
-    public <T> T record(Callable<T> f) throws MetricException {
+    public <T> T recordThrowable(ThrowableCallable<T> f) throws Throwable {
         final long s = clock.monotonicTime();
         try {
             return f.call();
-        } catch (Exception e) {
-            throw new MetricException(e);
         } finally {
             final long e = clock.monotonicTime();
             record(e - s, TimeUnit.NANOSECONDS);

src/main/java/org/springframework/metrics/instrument/scheduling/MetricsSchedulingAspect.java

@@ -0,0 +1,54 @@
+package org.springframework.metrics.instrument.scheduling;
+
+import org.apache.commons.logging.Log;
+import org.apache.commons.logging.LogFactory;
+import org.aspectj.lang.ProceedingJoinPoint;
+import org.aspectj.lang.annotation.Around;
+import org.aspectj.lang.annotation.Aspect;
+import org.aspectj.lang.reflect.MethodSignature;
+import org.springframework.metrics.instrument.MeterRegistry;
+import org.springframework.metrics.instrument.annotation.Timed;
+
+import java.lang.reflect.Method;
+
+@Aspect
+public class MetricsSchedulingAspect {
+    protected final Log logger = LogFactory.getLog(MetricsSchedulingAspect.class);
+
+    private final MeterRegistry registry;
+
+    public MetricsSchedulingAspect(MeterRegistry registry) {
+        this.registry = registry;
+    }
+
+    @Around("execution (@org.springframework.scheduling.annotation.Scheduled  * *.*(..))")
+    public Object timeScheduledOperation(ProceedingJoinPoint pjp) throws Throwable {
+        Method method = ((MethodSignature) pjp.getSignature()).getMethod();
+
+        String signature = pjp.getSignature().toShortString();
+
+        if (method.getDeclaringClass().isInterface()) {
+            try {
+                method = pjp.getTarget().getClass().getDeclaredMethod(pjp.getSignature().getName(),
+                        method.getParameterTypes());
+            } catch (final SecurityException | NoSuchMethodException e) {
+                logger.warn("Unable to perform metrics timing on " + signature, e);
+                return pjp.proceed();
+            }
+        }
+
+        Timed timed = method.getAnnotation(Timed.class);
+
+        if (timed == null) {
+            logger.debug("Skipping metrics timing on " + signature + ": no @Timed annotation is present on the method");
+            return pjp.proceed();
+        }
+
+        if (timed.value().isEmpty()) {
+            logger.warn("Unable to perform metrics timing on " + signature + ": @Timed annotation must have a value used to name the metric");
+            return pjp.proceed();
+        }
+
+        return registry.timer(timed.value()).recordThrowable(pjp::proceed);
+    }
+}

src/test/java/org/springframework/metrics/instrument/TimerTest.java

@@ -68,7 +68,7 @@ void recordWithRunnable(MeterRegistry registry) throws Exception {
         Timer t = registry.timer("myTimer");
 
         try {
-            t.record((Runnable) () -> clock(registry).addAndGetNanos(10));
+            t.record(() -> clock(registry).addAndGetNanos(10));
         } finally {
             assertAll(() -> assertEquals(1L, t.count()),
                     () -> assertEquals(10, t.totalTimeNanos() ,1.0e-12));
@@ -82,7 +82,7 @@ void recordCallableException(MeterRegistry registry) {
         Timer t = registry.timer("myTimer");
 
         assertThrows(Exception.class, () -> {
-            t.record(() -> {
+            t.recordThrowable(() -> {
                 clock(registry).addAndGetNanos(10);
                 throw new Exception("uh oh");
             });

src/test/java/org/springframework/metrics/instrument/scheduling/MetricsSchedulingAspectTest.java

@@ -0,0 +1,60 @@
+package org.springframework.metrics.instrument.scheduling;
+
+import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.extension.ExtendWith;
+import org.springframework.beans.factory.annotation.Autowired;
+import org.springframework.boot.autoconfigure.SpringBootApplication;
+import org.springframework.boot.test.context.SpringBootTest;
+import org.springframework.context.annotation.Bean;
+import org.springframework.metrics.boot.EnableMetrics;
+import org.springframework.metrics.instrument.MeterRegistry;
+import org.springframework.metrics.instrument.Timer;
+import org.springframework.metrics.instrument.annotation.Timed;
+import org.springframework.metrics.instrument.simple.SimpleMeterRegistry;
+import org.springframework.scheduling.annotation.EnableScheduling;
+import org.springframework.scheduling.annotation.Scheduled;
+import org.springframework.test.context.junit.jupiter.SpringExtension;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+@ExtendWith(SpringExtension.class)
+@SpringBootTest
+class MetricsSchedulingAspectTest {
+
+    @Autowired
+    MeterRegistry registry;
+
+    @Test
+    void scheduledIsInstrumented() {
+        assertThat(registry.findMeter(Timer.class, "beeper"))
+                .containsInstanceOf(Timer.class)
+                .hasValueSatisfying(t -> assertThat(t.count()).isEqualTo(1));
+    }
+
+    @SpringBootApplication
+    @EnableMetrics
+    @EnableScheduling
+    static class MetricsApp {
+        @Bean
+        MeterRegistry registry() {
+            return new SimpleMeterRegistry();
+        }
+
+        @Timed("beeper")
+        @Scheduled(fixedRate = 1000)
+        void beep1() {
+            System.out.println("beep");
+        }
+
+        @Timed // not instrumented because @Timed lacks a metric name
+        @Scheduled(fixedRate = 1000)
+        void beep2() {
+            System.out.println("beep");
+        }
+
+        @Scheduled(fixedRate = 1000) // not instrumented because it isn't @Timed
+        void beep3() {
+            System.out.println("beep");
+        }
+    }
+}