diff --git a/micrometer-spring-legacy/src/main/java/io/micrometer/spring/MetricsConfiguration.java b/micrometer-spring-legacy/src/main/java/io/micrometer/spring/MetricsConfiguration.java index ef9a65c2f8..eb267edc84 100644 --- a/micrometer-spring-legacy/src/main/java/io/micrometer/spring/MetricsConfiguration.java +++ b/micrometer-spring-legacy/src/main/java/io/micrometer/spring/MetricsConfiguration.java @@ -43,7 +43,7 @@ public TagFormatter tagFormatter() { @Configuration @ConditionalOnWebApplication - @Import(InstrumentServletRequestConfiguration.class) + @Import(MetricsServletRequestConfiguration.class) static class WebMvcConfiguration {} /** diff --git a/micrometer-spring-legacy/src/main/java/io/micrometer/spring/InstrumentServletRequestConfiguration.java b/micrometer-spring-legacy/src/main/java/io/micrometer/spring/MetricsServletRequestConfiguration.java similarity index 65% rename from micrometer-spring-legacy/src/main/java/io/micrometer/spring/InstrumentServletRequestConfiguration.java rename to micrometer-spring-legacy/src/main/java/io/micrometer/spring/MetricsServletRequestConfiguration.java index e61df4f94f..015a994812 100644 --- a/micrometer-spring-legacy/src/main/java/io/micrometer/spring/InstrumentServletRequestConfiguration.java +++ b/micrometer-spring-legacy/src/main/java/io/micrometer/spring/MetricsServletRequestConfiguration.java @@ -15,6 +15,8 @@ */ package io.micrometer.spring; +import io.micrometer.core.instrument.MeterRegistry; +import io.micrometer.spring.web.ControllerMetrics; import io.micrometer.spring.web.MetricsHandlerInterceptor; import io.micrometer.spring.web.WebmvcTagConfigurer; import org.springframework.beans.factory.annotation.Autowired; @@ -22,8 +24,6 @@ import org.springframework.context.annotation.Bean; import org.springframework.context.annotation.Configuration; import org.springframework.core.env.Environment; -import io.micrometer.core.instrument.MeterRegistry; -import io.micrometer.core.instrument.TagFormatter; import org.springframework.web.servlet.config.annotation.InterceptorRegistry; import org.springframework.web.servlet.config.annotation.WebMvcConfigurerAdapter; @@ -33,33 +33,32 @@ * @author Jon Schneider */ @Configuration -class InstrumentServletRequestConfiguration extends WebMvcConfigurerAdapter { - @Autowired - MeterRegistry registry; - - @Autowired(required = false) - WebmvcTagConfigurer tagConfigurer; - +class MetricsServletRequestConfiguration extends WebMvcConfigurerAdapter { @Bean @ConditionalOnMissingBean(WebmvcTagConfigurer.class) WebmvcTagConfigurer webmvcTagConfigurer() { - if(tagConfigurer != null) - return tagConfigurer; - this.tagConfigurer = new WebmvcTagConfigurer(); - return this.tagConfigurer; + return new WebmvcTagConfigurer(); } - @Autowired - Environment environment; - @Bean - MetricsHandlerInterceptor webMetricsInterceptor() { - return new MetricsHandlerInterceptor(registry, webmvcTagConfigurer(), + ControllerMetrics controllerMetrics(MeterRegistry registry, WebmvcTagConfigurer configurer, Environment environment) { + return new ControllerMetrics(registry, configurer, environment.getProperty("spring.metrics.web.server_requests.name", "http_server_requests")); } - @Override - public void addInterceptors(InterceptorRegistry registry) { - registry.addInterceptor(webMetricsInterceptor()); + @Bean + MetricsHandlerInterceptor webMetricsInterceptor(ControllerMetrics controllerMetrics) { + return new MetricsHandlerInterceptor(controllerMetrics); + } + + @Configuration + class MetricsServletRequestInterceptorConfiguration extends WebMvcConfigurerAdapter { + @Autowired + MetricsHandlerInterceptor handlerInterceptor; + + @Override + public void addInterceptors(InterceptorRegistry registry) { + registry.addInterceptor(handlerInterceptor); + } } } \ No newline at end of file diff --git a/micrometer-spring-legacy/src/main/java/io/micrometer/spring/web/ControllerMetrics.java b/micrometer-spring-legacy/src/main/java/io/micrometer/spring/web/ControllerMetrics.java new file mode 100644 index 0000000000..4c623be029 --- /dev/null +++ b/micrometer-spring-legacy/src/main/java/io/micrometer/spring/web/ControllerMetrics.java @@ -0,0 +1,143 @@ +/** + * Copyright 2017 Pivotal Software, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package io.micrometer.spring.web; + +import io.micrometer.core.annotation.Timed; +import io.micrometer.core.instrument.MeterRegistry; +import io.micrometer.core.instrument.Tag; +import io.micrometer.core.instrument.Timer; +import io.micrometer.core.instrument.stats.quantile.WindowSketchQuantiles; +import io.micrometer.core.instrument.util.AnnotationUtils; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; +import org.springframework.web.method.HandlerMethod; + +import javax.servlet.http.HttpServletRequest; +import javax.servlet.http.HttpServletResponse; +import java.lang.reflect.Method; +import java.util.Collections; +import java.util.Map; +import java.util.Set; +import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.TimeUnit; +import java.util.stream.Collectors; +import java.util.stream.IntStream; + +import static java.util.stream.Collectors.toSet; + +/** + * @author Jon Schneider + */ +public class ControllerMetrics { + private static final String TIMING_REQUEST_ATTRIBUTE = "micrometer.requestStartTime"; + private static final String HANDLER_REQUEST_ATTRIBUTE = "micrometer.handler"; + + private static final Log logger = LogFactory.getLog(ControllerMetrics.class); + + private final MeterRegistry registry; + private final WebmvcTagConfigurer tagConfigurer; + private final String metricName; + private final Map longTaskTimerIds = new ConcurrentHashMap<>(); + + public ControllerMetrics(MeterRegistry registry, + WebmvcTagConfigurer tagConfigurer, + String metricName) { + this.registry = registry; + this.tagConfigurer = tagConfigurer; + this.metricName = metricName; + } + + public void preHandle(HttpServletRequest request, HandlerMethod handler) { + request.setAttribute(TIMING_REQUEST_ATTRIBUTE, System.nanoTime()); + request.setAttribute(HANDLER_REQUEST_ATTRIBUTE, handler); + + longTaskTimed(handler).forEach(t -> { + if(t.value().isEmpty()) { + logger.warn("Unable to perform metrics timing on " + handler.getShortLogMessage() + ": @Timed annotation must have a value used to name the metric"); + return; + } + longTaskTimerIds.put(t, registry.longTaskTimer(t.value(), tagConfigurer.httpLongRequestTags(request, handler)).start()); + }); + } + + public void record(HttpServletRequest request, HttpServletResponse response, Throwable ex) { + Long startTime = (Long) request.getAttribute(TIMING_REQUEST_ATTRIBUTE); + Object handler = request.getAttribute(HANDLER_REQUEST_ATTRIBUTE); + + long endTime = System.nanoTime(); + + // complete any LongTaskTimer tasks running for this method + longTaskTimed(handler).forEach(t -> { + if(!t.value().isEmpty()) { + registry.longTaskTimer(t.value(), tagConfigurer.httpLongRequestTags(request, handler)).stop(longTaskTimerIds.remove(t)); + } + }); + + // record Timer values + timed(handler).forEach(t -> { + String name = metricName; + if (!t.value().isEmpty()) { + name = t.value(); + } + + Timer.Builder timerBuilder = registry.timerBuilder(name) + .tags(tagConfigurer.httpRequestTags(request, response, ex)); + + String[] extraTags = t.extraTags(); + if (extraTags.length > 0) { + if (extraTags.length % 2 != 0) { + if (logger.isErrorEnabled()) { + Method method = ((HandlerMethod) handler).getMethod(); + String target = method.getDeclaringClass().getName() + "." + method.getName(); + logger.error("@Timed extraTags array on method " + target + " size must be even, it is a set of key=value pairs"); + } + } else { + timerBuilder = timerBuilder.tags(IntStream.range(0, extraTags.length / 2) + .mapToObj(i -> Tag.of(extraTags[i], extraTags[i + 1])) + .collect(Collectors.toList())); + } + } + + if(t.quantiles().length > 0) { + timerBuilder = timerBuilder.quantiles(WindowSketchQuantiles.quantiles(t.quantiles()).create()); + } + + timerBuilder.create().record(endTime - startTime, TimeUnit.NANOSECONDS); + }); + } + + private Set longTaskTimed(Object m) { + if(!(m instanceof HandlerMethod)) + return Collections.emptySet(); + + Set timed = AnnotationUtils.findTimed(((HandlerMethod) m).getMethod()).filter(Timed::longTask).collect(toSet()); + if (timed.isEmpty()) { + return AnnotationUtils.findTimed(((HandlerMethod) m).getBeanType()).filter(Timed::longTask).collect(toSet()); + } + return timed; + } + + private Set timed(Object m) { + if(!(m instanceof HandlerMethod)) + return Collections.emptySet(); + + Set timed = AnnotationUtils.findTimed(((HandlerMethod) m).getMethod()).filter(t -> !t.longTask()).collect(toSet()); + if (timed.isEmpty()) { + return AnnotationUtils.findTimed(((HandlerMethod) m).getBeanType()).filter(t -> !t.longTask()).collect(toSet()); + } + return timed; + } +} diff --git a/micrometer-spring-legacy/src/main/java/io/micrometer/spring/web/MetricsHandlerInterceptor.java b/micrometer-spring-legacy/src/main/java/io/micrometer/spring/web/MetricsHandlerInterceptor.java index 3ffc814deb..441a6c13a6 100644 --- a/micrometer-spring-legacy/src/main/java/io/micrometer/spring/web/MetricsHandlerInterceptor.java +++ b/micrometer-spring-legacy/src/main/java/io/micrometer/spring/web/MetricsHandlerInterceptor.java @@ -15,31 +15,11 @@ */ package io.micrometer.spring.web; -import io.micrometer.core.annotation.Timed; -import io.micrometer.core.instrument.MeterRegistry; -import io.micrometer.core.instrument.Tag; -import io.micrometer.core.instrument.Timer; -import io.micrometer.core.instrument.util.AnnotationUtils; -import io.micrometer.core.instrument.stats.quantile.WindowSketchQuantiles; -import org.apache.commons.logging.Log; -import org.apache.commons.logging.LogFactory; -import org.springframework.web.context.request.RequestContextHolder; import org.springframework.web.method.HandlerMethod; import org.springframework.web.servlet.handler.HandlerInterceptorAdapter; import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; -import java.lang.reflect.Method; -import java.util.Collections; -import java.util.Map; -import java.util.Set; -import java.util.concurrent.ConcurrentHashMap; -import java.util.concurrent.TimeUnit; -import java.util.stream.Collectors; -import java.util.stream.IntStream; - -import static java.util.stream.Collectors.toSet; -import static org.springframework.web.context.request.RequestAttributes.SCOPE_REQUEST; /** * Intercepts incoming HTTP requests and records metrics about execution time and results. @@ -47,117 +27,23 @@ * @author Jon Schneider */ public class MetricsHandlerInterceptor extends HandlerInterceptorAdapter { + private final ControllerMetrics controllerMetrics; - private static final Log logger = LogFactory.getLog(MetricsHandlerInterceptor.class); - private static final String TIMING_REQUEST_ATTRIBUTE = "requestStartTime"; - - private final MeterRegistry registry; - private final WebmvcTagConfigurer tagConfigurer; - private final String metricName; - - private final Map longTaskTimerIds = new ConcurrentHashMap<>(); - - public MetricsHandlerInterceptor(MeterRegistry registry, - WebmvcTagConfigurer tagConfigurer, - String metricName) { - this.registry = registry; - this.tagConfigurer = tagConfigurer; - this.metricName = metricName; + public MetricsHandlerInterceptor(ControllerMetrics controllerMetrics) { + this.controllerMetrics = controllerMetrics; } @Override public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception { - longTaskTimed(handler).forEach(t -> { - if(t.value().isEmpty()) { - logger.warn("Unable to perform metrics timing on " + ((HandlerMethod) handler).getShortLogMessage() + ": @Timed annotation must have a value used to name the metric"); - return; - } - longTaskTimerIds.put(t, registry.longTaskTimer(t.value(), tagConfigurer.httpLongRequestTags(request, handler)).start()); - }); - - RequestContextHolder.getRequestAttributes().setAttribute(TIMING_REQUEST_ATTRIBUTE, - System.nanoTime(), SCOPE_REQUEST); + controllerMetrics.preHandle(request, (HandlerMethod) handler); return super.preHandle(request, response, handler); } @Override public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception { - RequestContextHolder.getRequestAttributes().setAttribute("exception", ex, - SCOPE_REQUEST); - - Long startTime = (Long) RequestContextHolder.getRequestAttributes().getAttribute( - TIMING_REQUEST_ATTRIBUTE, SCOPE_REQUEST); - if (startTime != null) - recordMetric(request, response, handler, startTime); - + controllerMetrics.record(request, response, ex); super.afterCompletion(request, response, handler, ex); } - - private void recordMetric(HttpServletRequest request, HttpServletResponse response, - Object handler, Long startTime) { - long endTime = System.nanoTime(); - - // complete any LongTaskTimer tasks running for this method - longTaskTimed(handler).forEach(t -> { - if(!t.value().isEmpty()) { - registry.longTaskTimer(t.value(), tagConfigurer.httpLongRequestTags(request, handler)).stop(longTaskTimerIds.remove(t)); - } - }); - - // record Timer values - timed(handler).forEach(t -> { - String name = metricName; - if (!t.value().isEmpty()) { - name = t.value(); - } - - Timer.Builder timerBuilder = registry.timerBuilder(name) - .tags(tagConfigurer.httpRequestTags(request, response)); - - String[] extraTags = t.extraTags(); - if (extraTags.length > 0) { - if (extraTags.length % 2 != 0) { - if (logger.isErrorEnabled()) { - Method method = ((HandlerMethod) handler).getMethod(); - String target = method.getDeclaringClass().getName() + "." + method.getName(); - logger.error("@Timed extraTags array on method " + target + " size must be even, it is a set of key=value pairs"); - } - } else { - timerBuilder = timerBuilder.tags(IntStream.range(0, extraTags.length / 2) - .mapToObj(i -> Tag.of(extraTags[i], extraTags[i + 1])) - .collect(Collectors.toList())); - } - } - - if(t.quantiles().length > 0) { - timerBuilder = timerBuilder.quantiles(WindowSketchQuantiles.quantiles(t.quantiles()).create()); - } - - timerBuilder.create().record(endTime - startTime, TimeUnit.NANOSECONDS); - }); - } - - private Set longTaskTimed(Object m) { - if(!(m instanceof HandlerMethod)) - return Collections.emptySet(); - - Set timed = AnnotationUtils.findTimed(((HandlerMethod) m).getMethod()).filter(Timed::longTask).collect(toSet()); - if (timed.isEmpty()) { - return AnnotationUtils.findTimed(((HandlerMethod) m).getBeanType()).filter(Timed::longTask).collect(toSet()); - } - return timed; - } - - private Set timed(Object m) { - if(!(m instanceof HandlerMethod)) - return Collections.emptySet(); - - Set timed = AnnotationUtils.findTimed(((HandlerMethod) m).getMethod()).filter(t -> !t.longTask()).collect(toSet()); - if (timed.isEmpty()) { - return AnnotationUtils.findTimed(((HandlerMethod) m).getBeanType()).filter(t -> !t.longTask()).collect(toSet()); - } - return timed; - } } diff --git a/micrometer-spring-legacy/src/main/java/io/micrometer/spring/web/WebmvcTagConfigurer.java b/micrometer-spring-legacy/src/main/java/io/micrometer/spring/web/WebmvcTagConfigurer.java index 0260106f18..9c21a4f5c8 100644 --- a/micrometer-spring-legacy/src/main/java/io/micrometer/spring/web/WebmvcTagConfigurer.java +++ b/micrometer-spring-legacy/src/main/java/io/micrometer/spring/web/WebmvcTagConfigurer.java @@ -49,8 +49,9 @@ public Iterable httpLongRequestTags(HttpServletRequest request, Object hand * @return A set of tags added to every Spring MVC HTTP request. */ public Iterable httpRequestTags(HttpServletRequest request, - HttpServletResponse response) { - return asList(method(request), uri(request), exception(request), status(response)); + HttpServletResponse response, + Throwable ex) { + return asList(method(request), uri(request), exception(ex), status(response)); } /** @@ -80,8 +81,7 @@ public Tag uri(HttpServletRequest request) { return Tag.of("uri", uri.isEmpty() ? "root" : uri); } - public Tag exception(HttpServletRequest request) { - Object exception = request.getAttribute("exception"); + public Tag exception(Throwable exception) { if (exception != null) { return Tag.of("exception", exception.getClass().getSimpleName()); } diff --git a/micrometer-spring-legacy/src/test/java/io/micrometer/spring/web/ControllerMetricsTest.java b/micrometer-spring-legacy/src/test/java/io/micrometer/spring/web/ControllerMetricsTest.java new file mode 100644 index 0000000000..92eab92e33 --- /dev/null +++ b/micrometer-spring-legacy/src/test/java/io/micrometer/spring/web/ControllerMetricsTest.java @@ -0,0 +1,100 @@ +/** + * Copyright 2017 Pivotal Software, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package io.micrometer.spring.web; + +import io.micrometer.core.annotation.Timed; +import io.micrometer.core.instrument.MeterRegistry; +import io.micrometer.core.instrument.Timer; +import io.micrometer.core.instrument.simple.SimpleMeterRegistry; +import io.micrometer.spring.EnableMetrics; +import org.junit.Test; +import org.junit.runner.RunWith; +import org.springframework.beans.factory.annotation.Autowired; +import org.springframework.boot.autoconfigure.SpringBootApplication; +import org.springframework.boot.test.autoconfigure.web.servlet.WebMvcTest; +import org.springframework.context.annotation.Bean; +import org.springframework.context.annotation.Import; +import org.springframework.http.HttpStatus; +import org.springframework.http.ResponseEntity; +import org.springframework.test.context.ContextConfiguration; +import org.springframework.test.context.junit4.SpringRunner; +import org.springframework.test.web.servlet.MockMvc; +import org.springframework.web.bind.annotation.*; + +import javax.servlet.http.HttpServletRequest; +import javax.servlet.http.HttpServletResponse; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.assertThatCode; +import static org.springframework.test.web.servlet.request.MockMvcRequestBuilders.get; +import static org.springframework.test.web.servlet.result.MockMvcResultMatchers.status; + +@RunWith(SpringRunner.class) +@ContextConfiguration(classes = ControllerMetricsTest.App.class) +@WebMvcTest(ControllerMetricsTest.Controller1.class) +public class ControllerMetricsTest { + @Autowired + private MockMvc mvc; + + @Autowired + private SimpleMeterRegistry registry; + + @Test + public void unhandledErrorCaughtByCustomExceptionHandler() throws Exception { + assertThatCode(() -> mvc.perform(get("/api/c1/unhandledError/10")).andExpect(status().isOk())); + assertThat(registry.findMeter(Timer.class, "http_server_requests", "exception", "RuntimeException")) + .hasValueSatisfying(t -> assertThat(t.count()).isEqualTo(1)); + } + + @SpringBootApplication(scanBasePackages = "isolated") + @EnableMetrics + @Import(Controller1.class) + static class App { + @Bean + MeterRegistry registry() { + return new SimpleMeterRegistry(); + } + } + + @ControllerAdvice + static class CustomExceptionHandler { + @Autowired + ControllerMetrics metrics; + + @ExceptionHandler + ResponseEntity handleDefaultError(HttpServletRequest request, + HttpServletResponse response, + Throwable ex) { + metrics.record(request, response, ex); + return new ResponseEntity<>("this is a custom exception body", HttpStatus.INTERNAL_SERVER_ERROR); + } + } + + @RestController + @RequestMapping("/api/c1") + static class Controller1 { + @Bean + public CustomExceptionHandler controllerAdvice() { + return new CustomExceptionHandler(); + } + + @Timed + @GetMapping("/unhandledError/{id}") + public String alwaysThrowsUnhandledException(@PathVariable Long id) { + throw new RuntimeException("Boom on $id!"); + } + } +}