Spring/spring-boot
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Refine WebMvcMetricsFilter for async support

Browse Source 
Rework `WebMvcMetricsFilter` so that async requests can be handled
correctly.

See gh-11348
This commit is contained in:
Phillip Webb
2018-01-26 19:23:44 -08:00
parent 112ffd7890
commit 25815ca7e1
9 changed files with 404 additions and 483 deletions
Download Patch File Download Diff File Expand all files Collapse all files

24
spring-boot-project/spring-boot-actuator-autoconfigure/src/main/java/org/springframework/boot/actuate/autoconfigure/metrics/web/servlet/WebMvcMetricsConfiguration.java
View File

@@ -19,17 +19,17 @@ package org.springframework.boot.actuate.autoconfigure.metrics.web.servlet;
import io.micrometer.core.instrument.MeterRegistry;
import org.springframework.boot.actuate.autoconfigure.metrics.MetricsProperties;
import org.springframework.boot.actuate.autoconfigure.metrics.MetricsProperties.Web.Server;
import org.springframework.boot.actuate.metrics.web.servlet.DefaultWebMvcTagsProvider;
import org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetrics;
import org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter;
import org.springframework.boot.actuate.metrics.web.servlet.WebMvcTagsProvider;
import org.springframework.boot.autoconfigure.condition.ConditionalOnClass;
import org.springframework.boot.autoconfigure.condition.ConditionalOnMissingBean;
import org.springframework.boot.autoconfigure.condition.ConditionalOnWebApplication;
import org.springframework.boot.context.properties.EnableConfigurationProperties;
import org.springframework.context.ApplicationContext;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.context.WebApplicationContext;
import org.springframework.web.servlet.DispatcherServlet;
/**
@@ -46,22 +46,18 @@ public class WebMvcMetricsConfiguration {
@Bean
@ConditionalOnMissingBean(WebMvcTagsProvider.class)
public DefaultWebMvcTagsProvider webmvcTagConfigurer() {
public DefaultWebMvcTagsProvider webMvcTagsProvider() {
return new DefaultWebMvcTagsProvider();
}
@Bean
public WebMvcMetrics controllerMetrics(MeterRegistry registry,
MetricsProperties properties, WebMvcTagsProvider configurer) {
return new WebMvcMetrics(registry, configurer,
properties.getWeb().getServer().getRequestsMetricName(),
properties.getWeb().getServer().isAutoTimeRequests(),
properties.getWeb().getServer().isRecordRequestPercentiles());
}
@Bean
public WebMvcMetricsFilter webMetricsFilter(ApplicationContext context) {
return new WebMvcMetricsFilter(context);
public WebMvcMetricsFilter webMetricsFilter(MeterRegistry registry,
MetricsProperties properties, WebMvcTagsProvider tagsProvider,
WebApplicationContext context) {
Server serverProperties = properties.getWeb().getServer();
return new WebMvcMetricsFilter(context, registry, tagsProvider,
serverProperties.getRequestsMetricName(),
serverProperties.isAutoTimeRequests());
}
}

32
spring-boot-project/spring-boot-actuator/src/main/java/org/springframework/boot/actuate/metrics/web/servlet/DefaultWebMvcTagsProvider.java
View File

@@ -1,5 +1,5 @@
/*
* Copyright 2012-2017 the original author or authors.
* Copyright 2012-2018 the original author or authors.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
@@ -16,12 +16,11 @@
package org.springframework.boot.actuate.metrics.web.servlet;
import java.util.Arrays;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import io.micrometer.core.instrument.Tag;
import io.micrometer.core.instrument.Tags;
/**
* Default implementation of {@link WebMvcTagsProvider}.
@@ -31,31 +30,16 @@ import io.micrometer.core.instrument.Tag;
*/
public class DefaultWebMvcTagsProvider implements WebMvcTagsProvider {
/**
* Supplies default tags to long task timers.
* @param request The HTTP request.
* @param handler The request method that is responsible for handling the request.
* @return A set of tags added to every Spring MVC HTTP request
*/
@Override
public Iterable<Tag> httpLongRequestTags(HttpServletRequest request, Object handler) {
return Arrays.asList(WebMvcTags.method(request), WebMvcTags.uri(request, null));
public Iterable<Tag> getTags(HttpServletRequest request, HttpServletResponse response,
Object handler, Throwable exception) {
return Tags.of(WebMvcTags.method(request), WebMvcTags.uri(request, response),
WebMvcTags.exception(exception), WebMvcTags.status(response));
}
/**
* Supplies default tags to the Web MVC server programming model.
* @param request The HTTP request.
* @param handler the Spring MVC handler for the request
* @param response The HTTP response.
* @param ex The current exception, if any
* @return A set of tags added to every Spring MVC HTTP request.
*/
@Override
public Iterable<Tag> httpRequestTags(HttpServletRequest request, Object handler,
HttpServletResponse response, Throwable ex) {
return Arrays.asList(WebMvcTags.method(request),
WebMvcTags.uri(request, response), WebMvcTags.exception(ex),
WebMvcTags.status(response));
public Iterable<Tag> getLongRequestTags(HttpServletRequest request, Object handler) {
return Tags.of(WebMvcTags.method(request), WebMvcTags.uri(request, null));
}
}

318
spring-boot-project/spring-boot-actuator/src/main/java/org/springframework/boot/actuate/metrics/web/servlet/WebMvcMetrics.java
View File

@@ -1,318 +0,0 @@
/*
* Copyright 2012-2018 the original author or authors.
*
* 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 org.springframework.boot.actuate.metrics.web.servlet;
import java.lang.reflect.AnnotatedElement;
import java.util.Arrays;
import java.util.Collections;
import java.util.IdentityHashMap;
import java.util.Map;
import java.util.Set;
import java.util.concurrent.TimeUnit;
import java.util.function.Supplier;
import java.util.stream.Collectors;
import java.util.stream.Stream;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import io.micrometer.core.annotation.Timed;
import io.micrometer.core.annotation.TimedSet;
import io.micrometer.core.instrument.LongTaskTimer;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Tags;
import io.micrometer.core.instrument.Timer;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.springframework.core.annotation.AnnotationUtils;
import org.springframework.util.ObjectUtils;
import org.springframework.web.context.request.RequestAttributes;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.method.HandlerMethod;
import org.springframework.web.servlet.mvc.ParameterizableViewController;
import org.springframework.web.servlet.resource.ResourceHttpRequestHandler;
/**
* Support class for Spring MVC metrics.
*
* @author Jon Schneider
* @since 2.0.0
*/
public class WebMvcMetrics {
private static final String TIMING_REQUEST_ATTRIBUTE = "micrometer.requestStartTime";
private static final String HANDLER_REQUEST_ATTRIBUTE = "micrometer.requestHandler";
private static final String EXCEPTION_ATTRIBUTE = "micrometer.requestException";
private static final Log logger = LogFactory.getLog(WebMvcMetrics.class);
private final Map<HttpServletRequest, LongTaskTimer.Sample> longTaskTimerSamples = Collections
.synchronizedMap(new IdentityHashMap<>());
private final MeterRegistry registry;
private final WebMvcTagsProvider tagsProvider;
private final String metricName;
private final boolean autoTimeRequests;
private final boolean recordAsPercentiles;
public WebMvcMetrics(MeterRegistry registry, WebMvcTagsProvider tagsProvider,
String metricName, boolean autoTimeRequests, boolean recordAsPercentiles) {
this.registry = registry;
this.tagsProvider = tagsProvider;
this.metricName = metricName;
this.autoTimeRequests = autoTimeRequests;
this.recordAsPercentiles = recordAsPercentiles;
}
public void tagWithException(Throwable exception) {
RequestAttributes attributes = RequestContextHolder.getRequestAttributes();
attributes.setAttribute(EXCEPTION_ATTRIBUTE, exception,
RequestAttributes.SCOPE_REQUEST);
}
void preHandle(HttpServletRequest request, Object handler) {
if (request.getAttribute(TIMING_REQUEST_ATTRIBUTE) == null) {
request.setAttribute(TIMING_REQUEST_ATTRIBUTE,
this.registry.config().clock().monotonicTime());
}
request.setAttribute(HANDLER_REQUEST_ATTRIBUTE, handler);
longTaskTimed(handler).forEach((config) -> {
if (config.getName() == null) {
logWarning(request, handler);
return;
}
this.longTaskTimerSamples.put(request,
longTaskTimer(config, request, handler).start());
});
}
private void logWarning(HttpServletRequest request, Object handler) {
if (handler instanceof HandlerMethod) {
logger.warn("Unable to perform metrics timing on "
+ ((HandlerMethod) handler).getShortLogMessage()
+ ": @Timed annotation must have a value used to name the metric");
return;
}
logger.warn("Unable to perform metrics timing for request "
+ request.getRequestURI()
+ ": @Timed annotation must have a value used to name the metric");
}
void record(HttpServletRequest request, HttpServletResponse response, Throwable ex) {
Object handler = request.getAttribute(HANDLER_REQUEST_ATTRIBUTE);
Long startTime = (Long) request.getAttribute(TIMING_REQUEST_ATTRIBUTE);
long endTime = System.nanoTime();
completeLongTimerTasks(request, handler);
Throwable thrown = (ex != null ? ex
: (Throwable) request.getAttribute(EXCEPTION_ATTRIBUTE));
recordTimerTasks(request, response, handler, startTime, endTime, thrown);
}
private void completeLongTimerTasks(HttpServletRequest request, Object handler) {
longTaskTimed(handler)
.forEach((config) -> completeLongTimerTask(request, handler, config));
}
private void completeLongTimerTask(HttpServletRequest request, Object handler,
TimerConfig config) {
if (config.getName() != null) {
LongTaskTimer.Sample sample = this.longTaskTimerSamples.remove(request);
if (sample != null) {
sample.stop();
}
}
}
private void recordTimerTasks(HttpServletRequest request,
HttpServletResponse response, Object handler, Long startTime, long endTime,
Throwable thrown) {
// record Timer values
timed(handler).forEach((config) -> {
Timer.Builder builder = getTimerBuilder(request, handler, response, thrown,
config);
long amount = endTime - startTime;
builder.register(this.registry).record(amount, TimeUnit.NANOSECONDS);
});
}
private Timer.Builder getTimerBuilder(HttpServletRequest request, Object handler,
HttpServletResponse response, Throwable thrown, TimerConfig config) {
Timer.Builder builder = Timer.builder(config.getName())
.tags(this.tagsProvider.httpRequestTags(request, handler, response,
thrown))
.tags(config.getExtraTags()).description("Timer of servlet request")
.publishPercentileHistogram(config.isHistogram());
if (config.getPercentiles().length > 0) {
builder = builder.publishPercentiles(config.getPercentiles());
}
return builder;
}
private LongTaskTimer longTaskTimer(TimerConfig config, HttpServletRequest request,
Object handler) {
return LongTaskTimer.builder(config.getName())
.tags(this.tagsProvider.httpLongRequestTags(request, handler))
.tags(config.getExtraTags()).description("Timer of long servlet request")
.register(this.registry);
}
private Set<TimerConfig> longTaskTimed(Object handler) {
if (handler instanceof HandlerMethod) {
return longTaskTimed((HandlerMethod) handler);
}
return Collections.emptySet();
}
private Set<TimerConfig> longTaskTimed(HandlerMethod handler) {
Set<TimerConfig> timed = getLongTaskAnnotationConfig(handler.getMethod());
if (timed.isEmpty()) {
return getLongTaskAnnotationConfig(handler.getBeanType());
}
return timed;
}
private Set<TimerConfig> timed(Object handler) {
if (handler instanceof HandlerMethod) {
return timed((HandlerMethod) handler);
}
if ((handler == null || handler instanceof ResourceHttpRequestHandler
|| handler instanceof ParameterizableViewController)
&& this.autoTimeRequests) {
return Collections.singleton(
new TimerConfig(getServerRequestName(), this.recordAsPercentiles));
}
return Collections.emptySet();
}
private Set<TimerConfig> timed(HandlerMethod handler) {
Set<TimerConfig> config = getNonLongTaskAnnotationConfig(handler.getMethod());
if (config.isEmpty()) {
config = getNonLongTaskAnnotationConfig(handler.getBeanType());
if (config.isEmpty() && this.autoTimeRequests) {
return Collections.singleton(new TimerConfig(getServerRequestName(),
this.recordAsPercentiles));
}
}
return config;
}
private Set<TimerConfig> getNonLongTaskAnnotationConfig(AnnotatedElement element) {
return findTimedAnnotations(element).filter((t) -> !t.longTask())
.map(this::fromAnnotation).collect(Collectors.toSet());
}
private Set<TimerConfig> getLongTaskAnnotationConfig(AnnotatedElement element) {
return findTimedAnnotations(element).filter(Timed::longTask)
.map(this::fromAnnotation).collect(Collectors.toSet());
}
private Stream<Timed> findTimedAnnotations(AnnotatedElement element) {
Timed timed = AnnotationUtils.findAnnotation(element, Timed.class);
if (timed != null) {
return Stream.of(timed);
}
TimedSet ts = AnnotationUtils.findAnnotation(element, TimedSet.class);
if (ts != null) {
return Arrays.stream(ts.value());
}
return Stream.empty();
}
private TimerConfig fromAnnotation(Timed timed) {
return new TimerConfig(timed, this::getServerRequestName);
}
private String getServerRequestName() {
return this.metricName;
}
private static class TimerConfig {
private final String name;
private final Tags extraTags;
private final double[] percentiles;
private final boolean histogram;
TimerConfig(String name, boolean histogram) {
this.name = name;
this.extraTags = Tags.empty();
this.percentiles = new double[0];
this.histogram = histogram;
}
TimerConfig(Timed timed, Supplier<String> name) {
this.name = buildName(timed, name);
this.extraTags = Tags.of(timed.extraTags());
this.percentiles = timed.percentiles();
this.histogram = timed.histogram();
}
private String buildName(Timed timed, Supplier<String> name) {
if (timed.longTask() && timed.value().isEmpty()) {
// the user MUST name long task timers, we don't lump them in with regular
// timers with the same name
return null;
}
return (timed.value().isEmpty() ? name.get() : timed.value());
}
public String getName() {
return this.name;
}
Tags getExtraTags() {
return this.extraTags;
}
double[] getPercentiles() {
return this.percentiles;
}
boolean isHistogram() {
return this.histogram;
}
@Override
public boolean equals(Object o) {
if (this == o) {
return true;
}
if (o == null || getClass() != o.getClass()) {
return false;
}
TimerConfig other = (TimerConfig) o;
return ObjectUtils.nullSafeEquals(this.name, other.name);
}
@Override
public int hashCode() {
return ObjectUtils.nullSafeHashCode(this.name);
}
}
}

216
spring-boot-project/spring-boot-actuator/src/main/java/org/springframework/boot/actuate/metrics/web/servlet/WebMvcMetricsFilter.java
View File

@@ -17,20 +17,37 @@
package org.springframework.boot.actuate.metrics.web.servlet;
import java.io.IOException;
import java.lang.reflect.AnnotatedElement;
import java.util.ArrayList;
import java.util.Collection;
import java.util.Collections;
import java.util.List;
import java.util.Set;
import java.util.function.Supplier;
import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import io.micrometer.core.annotation.Timed;
import io.micrometer.core.instrument.LongTaskTimer;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Tag;
import io.micrometer.core.instrument.Timer;
import io.micrometer.core.instrument.Timer.Builder;
import io.micrometer.core.instrument.Timer.Sample;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.context.ApplicationContext;
import org.springframework.core.Ordered;
import org.springframework.core.annotation.AnnotationUtils;
import org.springframework.core.annotation.Order;
import org.springframework.http.HttpStatus;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.method.HandlerMethod;
import org.springframework.web.servlet.DispatcherServlet;
import org.springframework.web.servlet.HandlerExecutionChain;
import org.springframework.web.servlet.handler.HandlerMappingIntrospector;
import org.springframework.web.servlet.handler.MatchableHandlerMapping;
@@ -41,6 +58,7 @@ import org.springframework.web.util.NestedServletException;
* and results.
*
* @author Jon Schneider
* @author Phillip Webb
* @since 2.0.0
*/
@Order(Ordered.HIGHEST_PRECEDENCE + 1)
@@ -51,12 +69,32 @@ public class WebMvcMetricsFilter extends OncePerRequestFilter {
private final ApplicationContext context;
private volatile WebMvcMetrics webMvcMetrics;
private final MeterRegistry registry;
private volatile HandlerMappingIntrospector mappingIntrospector;
private final WebMvcTagsProvider tagsProvider;
public WebMvcMetricsFilter(ApplicationContext context) {
private final String metricName;
private final boolean autoTimeRequests;
private volatile HandlerMappingIntrospector introspector;
/**
* Create a new {@link WebMvcMetricsFilter} instance.
* @param context the source application context
* @param registry the meter registry
* @param tagsProvider the tags provier
* @param metricName the metric name
* @param autoTimeRequests if requests should be automatically timed
*/
public WebMvcMetricsFilter(ApplicationContext context, MeterRegistry registry,
WebMvcTagsProvider tagsProvider, String metricName,
boolean autoTimeRequests) {
this.context = context;
this.registry = registry;
this.tagsProvider = tagsProvider;
this.metricName = metricName;
this.autoTimeRequests = autoTimeRequests;
}
@Override
@@ -68,60 +106,170 @@ public class WebMvcMetricsFilter extends OncePerRequestFilter {
protected void doFilterInternal(HttpServletRequest request,
HttpServletResponse response, FilterChain filterChain)
throws ServletException, IOException {
HandlerExecutionChain handlerExecutionChain = getHandlerExecutionChain(request);
Object handler = (handlerExecutionChain == null ? null
: handlerExecutionChain.getHandler());
filterWithMetrics(request, response, filterChain, handler);
filterAndRecordMetrics(request, response, filterChain);
}
private HandlerExecutionChain getHandlerExecutionChain(HttpServletRequest request) {
private void filterAndRecordMetrics(HttpServletRequest request,
HttpServletResponse response, FilterChain filterChain)
throws IOException, ServletException, NestedServletException {
Object handler = null;
try {
MatchableHandlerMapping matchableHandlerMapping = getMappingIntrospector()
.getMatchableHandlerMapping(request);
return (matchableHandlerMapping == null ? null
: matchableHandlerMapping.getHandler(request));
handler = getHandler(request);
}
catch (Exception ex) {
if (logger.isDebugEnabled()) {
logger.debug("Unable to time request", ex);
}
return null;
logger.debug("Unable to time request", ex);
filterChain.doFilter(request, response);
return;
}
filterAndRecordMetrics(request, response, filterChain, handler);
}
private void filterWithMetrics(HttpServletRequest request,
private Object getHandler(HttpServletRequest request) throws Exception {
MatchableHandlerMapping handlerMapping = getMappingIntrospector()
.getMatchableHandlerMapping(request);
HandlerExecutionChain chain = (handlerMapping == null ? null
: handlerMapping.getHandler(request));
return (chain == null ? null : chain.getHandler());
}
private HandlerMappingIntrospector getMappingIntrospector() {
if (this.introspector == null) {
this.introspector = this.context.getBean(HandlerMappingIntrospector.class);
}
return this.introspector;
}
private void filterAndRecordMetrics(HttpServletRequest request,
HttpServletResponse response, FilterChain filterChain, Object handler)
throws IOException, ServletException {
WebMvcMetrics metrics = getWebMvcMetrics();
metrics.preHandle(request, handler);
throws IOException, ServletException, NestedServletException {
TimingContext timingContext = TimingContext.get(request);
if (timingContext == null) {
timingContext = startAndAttachTimingContext(request, handler);
}
try {
filterChain.doFilter(request, response);
// When an async operation is complete, the whole filter gets called again
// with isAsyncStarted = false
if (!request.isAsyncStarted()) {
metrics.record(request, response, null);
// Only record when async processing has finished or never been started.
// If async was started by something further down the chain we wait
// until the second filter invocation (but we'll be using the
// TimingContext that was attached to the first)
Throwable exception = (Throwable) request
.getAttribute(DispatcherServlet.EXCEPTION_ATTRIBUTE);
record(timingContext, response, request, handler, exception);
}
}
catch (NestedServletException ex) {
response.setStatus(HttpStatus.INTERNAL_SERVER_ERROR.value());
metrics.record(request, response, ex.getCause());
record(timingContext, response, request, handler, ex.getCause());
throw ex;
}
}
private HandlerMappingIntrospector getMappingIntrospector() {
if (this.mappingIntrospector == null) {
this.mappingIntrospector = this.context
.getBean(HandlerMappingIntrospector.class);
}
return this.mappingIntrospector;
private TimingContext startAndAttachTimingContext(HttpServletRequest request,
Object handler) {
Set<Timed> annotations = getTimedAnnotations(handler);
Timer.Sample timerSample = Timer.start(this.registry);
Collection<LongTaskTimer.Sample> longTaskTimerSamples = getLongTaskTimerSamples(
request, handler, annotations);
TimingContext timingContext = new TimingContext(annotations, timerSample,
longTaskTimerSamples);
timingContext.attachTo(request);
return timingContext;
}
private WebMvcMetrics getWebMvcMetrics() {
if (this.webMvcMetrics == null) {
this.webMvcMetrics = this.context.getBean(WebMvcMetrics.class);
private Set<Timed> getTimedAnnotations(Object handler) {
if (!(handler instanceof HandlerMethod)) {
return Collections.emptySet();
}
return this.webMvcMetrics;
return getTimedAnnotations((HandlerMethod) handler);
}
private Set<Timed> getTimedAnnotations(HandlerMethod handler) {
Set<Timed> timed = findTimedAnnotations(handler.getMethod());
if (timed.isEmpty()) {
return findTimedAnnotations(handler.getBeanType());
}
return timed;
}
private Set<Timed> findTimedAnnotations(AnnotatedElement element) {
return AnnotationUtils.getDeclaredRepeatableAnnotations(element, Timed.class);
}
private Collection<LongTaskTimer.Sample> getLongTaskTimerSamples(
HttpServletRequest request, Object handler, Set<Timed> annotations) {
List<LongTaskTimer.Sample> samples = new ArrayList<>();
annotations.stream().filter(Timed::longTask).forEach((annotation) -> {
Iterable<Tag> tags = this.tagsProvider.getLongRequestTags(request, handler);
LongTaskTimer.Builder builder = LongTaskTimer.builder(annotation).tags(tags);
LongTaskTimer timer = builder.register(this.registry);
samples.add(timer.start());
});
return samples;
}
private void record(TimingContext timingContext, HttpServletResponse response,
HttpServletRequest request, Object handlerObject, Throwable exception) {
Timer.Sample timerSample = timingContext.getTimerSample();
Supplier<Iterable<Tag>> tags = () -> this.tagsProvider.getTags(request,
response, handlerObject, exception);
for (Timed annotation : timingContext.getAnnotations()) {
stop(timerSample, tags, Timer.builder(annotation, this.metricName));
}
if (timingContext.getAnnotations().isEmpty() && this.autoTimeRequests) {
stop(timerSample, tags, Timer.builder(this.metricName));
}
for (LongTaskTimer.Sample sample : timingContext.getLongTaskTimerSamples()) {
sample.stop();
}
}
private void stop(Timer.Sample timerSample, Supplier<Iterable<Tag>> tags,
Builder builder) {
timerSample.stop(builder.tags(tags.get()).register(this.registry));
}
/**
* Context object attached to a request to retain information across the multiple
* filter calls that happen with async requests.
*/
private static class TimingContext {
private static final String ATTRIBUTE = TimingContext.class.getName();
private final Set<Timed> annotations;
private final Timer.Sample timerSample;
private final Collection<LongTaskTimer.Sample> longTaskTimerSamples;
TimingContext(Set<Timed> annotations, Sample timerSample,
Collection<io.micrometer.core.instrument.LongTaskTimer.Sample> longTaskTimerSamples) {
this.annotations = annotations;
this.timerSample = timerSample;
this.longTaskTimerSamples = longTaskTimerSamples;
}
public Set<Timed> getAnnotations() {
return this.annotations;
}
public Timer.Sample getTimerSample() {
return this.timerSample;
}
public Collection<LongTaskTimer.Sample> getLongTaskTimerSamples() {
return this.longTaskTimerSamples;
}
public void attachTo(HttpServletRequest request) {
request.setAttribute(ATTRIBUTE, this);
}
public static TimingContext get(HttpServletRequest request) {
return (TimingContext) request.getAttribute(ATTRIBUTE);
}
}
}

31
spring-boot-project/spring-boot-actuator/src/main/java/org/springframework/boot/actuate/metrics/web/servlet/WebMvcTags.java
View File

@@ -45,7 +45,8 @@ public final class WebMvcTags {
* @return the method tag whose value is a capitalized method (e.g. GET).
*/
public static Tag method(HttpServletRequest request) {
return Tag.of("method", request.getMethod());
return (request == null ? Tag.of("method", "UNKNOWN")
: Tag.of("method", request.getMethod()));
}
/**
@@ -54,7 +55,8 @@ public final class WebMvcTags {
* @return the status tag derived from the status of the response
*/
public static Tag status(HttpServletResponse response) {
return Tag.of("status", ((Integer) response.getStatus()).toString());
return (response == null ? Tag.of("status", "UNKNOWN")
: Tag.of("status", ((Integer) response.getStatus()).toString()));
}
/**
@@ -72,18 +74,14 @@ public final class WebMvcTags {
if (status != null && status.is3xxRedirection()) {
return Tag.of("uri", "REDIRECTION");
}
if (HttpStatus.NOT_FOUND.equals(status)) {
if (status != null && status.equals(HttpStatus.NOT_FOUND)) {
return Tag.of("uri", "NOT_FOUND");
}
}
String uri = (String) request
.getAttribute(HandlerMapping.BEST_MATCHING_PATTERN_ATTRIBUTE);
if (uri == null) {
uri = request.getPathInfo();
}
if (!StringUtils.hasText(uri)) {
uri = "/";
if (request == null) {
return Tag.of("uri", "UNKNOWN");
}
String uri = getUri(request);
uri = uri.replaceAll("//+", "/").replaceAll("/$", "");
return Tag.of("uri", uri.isEmpty() ? "root" : uri);
}
@@ -97,6 +95,13 @@ public final class WebMvcTags {
}
}
private static String getUri(HttpServletRequest request) {
String uri = (String) request
.getAttribute(HandlerMapping.BEST_MATCHING_PATTERN_ATTRIBUTE);
uri = (uri != null ? uri : request.getPathInfo());
return (StringUtils.hasText(uri) ? uri : "/");
}
/**
* Creates a {@code exception} tag based on the {@link Class#getSimpleName() simple
* name} of the class of the given {@code exception}.
@@ -104,10 +109,8 @@ public final class WebMvcTags {
* @return the exception tag derived from the exception
*/
public static Tag exception(Throwable exception) {
if (exception != null) {
return Tag.of("exception", exception.getClass().getSimpleName());
}
return Tag.of("exception", "None");
return Tag.of("exception",
(exception == null ? "None" : exception.getClass().getSimpleName()));
}
}

30
spring-boot-project/spring-boot-actuator/src/main/java/org/springframework/boot/actuate/metrics/web/servlet/WebMvcTagsProvider.java
View File

@@ -1,5 +1,5 @@
/*
* Copyright 2012-2017 the original author or authors.
* Copyright 2012-2018 the original author or authors.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
@@ -31,24 +31,26 @@ import io.micrometer.core.instrument.Tag;
*/
public interface WebMvcTagsProvider {
/**
* Provides tags to be used by {@link LongTaskTimer long task timers}.
* @param request the HTTP request
* @param handler the handler for the request
* @return tags to associate with metrics recorded for the request
*/
Iterable<Tag> httpLongRequestTags(HttpServletRequest request, Object handler);
/**
* Provides tags to be associated with metrics for the given {@code request} and
* {@code response} exchange. The request was handled by the given {@code handler}.
* {@code response} exchange.
* @param request the request
* @param handler the handler
* @param response the response
* @param ex the current exception, if any
* @param handler the handler for the request or {@code null} if the handler is
* unknown
* @param exception the current exception, if any
* @return tags to associate with metrics for the request and response exchange
*/
Iterable<Tag> httpRequestTags(HttpServletRequest request, Object handler,
HttpServletResponse response, Throwable ex);
Iterable<Tag> getTags(HttpServletRequest request, HttpServletResponse response,
Object handler, Throwable exception);
/**
* Provides tags to be used by {@link LongTaskTimer long task timers}.
* @param request the HTTP request
* @param handler the handler for the request or {@code null} if the handler is
* unknown
* @return tags to associate with metrics recorded for the request
*/
Iterable<Tag> getLongRequestTags(HttpServletRequest request, Object handler);
}

15
spring-boot-project/spring-boot-actuator/src/test/java/org/springframework/boot/actuate/metrics/web/servlet/WebMvcMetricsFilterAutoTimedTests.java
View File

@@ -26,7 +26,6 @@ import org.junit.Test;
import org.junit.runner.RunWith;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.context.ApplicationContext;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.Import;
@@ -46,6 +45,8 @@ import static org.springframework.test.web.servlet.request.MockMvcRequestBuilder
import static org.springframework.test.web.servlet.result.MockMvcResultMatchers.status;
/**
* Test for {@link WebMvcMetricsFilter} with auto-timed enabled.
*
* @author Jon Schneider
*/
@RunWith(SpringRunner.class)
@@ -92,14 +93,10 @@ public class WebMvcMetricsFilterAutoTimedTests {
}
@Bean
public WebMvcMetrics controllerMetrics(MeterRegistry registry) {
return new WebMvcMetrics(registry, new DefaultWebMvcTagsProvider(),
"http.server.requests", true, false);
}
@Bean
public WebMvcMetricsFilter webMetricsFilter(ApplicationContext context) {
return new WebMvcMetricsFilter(context);
public WebMvcMetricsFilter webMetricsFilter(WebApplicationContext context,
MeterRegistry registry) {
return new WebMvcMetricsFilter(context, registry,
new DefaultWebMvcTagsProvider(), "http.server.requests", true);
}
}

196
spring-boot-project/spring-boot-actuator/src/test/java/org/springframework/boot/actuate/metrics/web/servlet/WebMvcMetricsFilterTests.java
View File

@@ -21,9 +21,14 @@ import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;
import java.time.Duration;
import java.util.Collection;
import java.util.concurrent.BrokenBarrierException;
import java.util.concurrent.Callable;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.CyclicBarrier;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicReference;
import javax.servlet.FilterChain;
import javax.servlet.ServletException;
@@ -34,11 +39,14 @@ import io.micrometer.core.annotation.Timed;
import io.micrometer.core.instrument.Clock;
import io.micrometer.core.instrument.Meter;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.MockClock;
import io.micrometer.core.instrument.Tag;
import io.micrometer.core.instrument.composite.CompositeMeterRegistry;
import io.micrometer.core.instrument.config.MeterFilter;
import io.micrometer.core.instrument.config.MeterFilterReply;
import io.micrometer.core.instrument.simple.SimpleConfig;
import io.micrometer.core.instrument.simple.SimpleMeterRegistry;
import io.micrometer.core.lang.NonNull;
import io.micrometer.prometheus.PrometheusConfig;
import io.micrometer.prometheus.PrometheusMeterRegistry;
import io.prometheus.client.CollectorRegistry;
@@ -47,7 +55,7 @@ import org.junit.Test;
import org.junit.runner.RunWith;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.context.ApplicationContext;
import org.springframework.beans.factory.annotation.Qualifier;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.Import;
@@ -68,9 +76,12 @@ import org.springframework.web.context.WebApplicationContext;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.servlet.ModelAndView;
import org.springframework.web.servlet.config.annotation.EnableWebMvc;
import org.springframework.web.util.NestedServletException;
import static org.assertj.core.api.Assertions.assertThat;
import static org.assertj.core.api.Assertions.assertThatCode;
import static org.assertj.core.api.Assertions.assertThatExceptionOfType;
import static org.assertj.core.api.Assertions.fail;
import static org.springframework.test.web.servlet.request.MockMvcRequestBuilders.asyncDispatch;
import static org.springframework.test.web.servlet.request.MockMvcRequestBuilders.get;
import static org.springframework.test.web.servlet.result.MockMvcResultMatchers.request;
@@ -100,7 +111,12 @@ public class WebMvcMetricsFilterTests {
private MockMvc mvc;
@Autowired
private CountDownLatch asyncLatch;
@Qualifier("callableBarrier")
private CyclicBarrier callableBarrier;
@Autowired
@Qualifier("completableFutureBarrier")
private CyclicBarrier completableFutureBarrier;
@Before
public void setupMockMvc() {
@@ -113,7 +129,7 @@ public class WebMvcMetricsFilterTests {
this.mvc.perform(get("/api/c1/10")).andExpect(status().isOk());
assertThat(this.registry.get("http.server.requests")
.tags("status", "200", "uri", "/api/c1/{id}", "public", "true").timer()
.count()).isEqualTo(1L);
.count()).isEqualTo(1);
}
@Test
@@ -173,20 +189,80 @@ public class WebMvcMetricsFilterTests {
}
@Test
public void longRunningRequest() throws Exception {
MvcResult result = this.mvc.perform(get("/api/c1/long/10"))
.andExpect(request().asyncStarted()).andReturn();
// the request is not prematurely recorded as complete
public void asyncCallableRequest() throws Exception {
AtomicReference<MvcResult> result = new AtomicReference<>();
Thread backgroundRequest = new Thread(() -> {
try {
result.set(this.mvc.perform(get("/api/c1/callable/10"))
.andExpect(request().asyncStarted()).andReturn());
}
catch (Exception ex) {
fail("Failed to execute async request", ex);
}
});
backgroundRequest.start();
assertThat(this.registry.find("http.server.requests").tags("uri", "/api/c1/async")
.timer()).isNull();
.timer()).describedAs("Request isn't prematurely recorded as complete")
.isNull();
// once the mapping completes, we can gather information about status, etc.
this.callableBarrier.await();
MockClock.clock(this.registry).add(Duration.ofSeconds(2));
// while the mapping is running, it contributes to the activeTasks count
assertThat(this.registry.get("my.long.request").tags("region", "test")
.longTaskTimer().activeTasks()).isEqualTo(1);
// once the mapping completes, we can gather information about status, etc.
this.asyncLatch.countDown();
this.mvc.perform(asyncDispatch(result)).andExpect(status().isOk());
assertThat(this.registry.get("http.server.requests").tags("status", "200").timer()
.count()).isEqualTo(1L);
this.callableBarrier.await();
backgroundRequest.join();
this.mvc.perform(asyncDispatch(result.get())).andExpect(status().isOk());
assertThat(this.registry.get("http.server.requests").tags("status", "200")
.tags("uri", "/api/c1/callable/{id}").timer().totalTime(TimeUnit.SECONDS))
.isEqualTo(2L);
// once the async dispatch is complete, it should no longer contribute to the
// activeTasks count
assertThat(this.registry.get("my.long.request").tags("region", "test")
.longTaskTimer().activeTasks()).isEqualTo(0);
}
@Test
public void asyncRequestThatThrowsUncheckedException() throws Exception {
MvcResult result = this.mvc.perform(get("/api/c1/completableFutureException"))
.andExpect(request().asyncStarted()).andReturn();
// once the async dispatch is complete, it should no longer contribute to the
// activeTasks count
assertThat(this.registry.get("my.long.request.exception").longTaskTimer()
.activeTasks()).isEqualTo(1);
assertThatExceptionOfType(NestedServletException.class)
.isThrownBy(() -> this.mvc.perform(asyncDispatch(result)))
.withRootCauseInstanceOf(RuntimeException.class);
assertThat(this.registry.get("http.server.requests")
.tags("uri", "/api/c1/completableFutureException").timer().count())
.isEqualTo(1);
// once the async dispatch is complete, it should no longer contribute to the
// activeTasks count
assertThat(this.registry.get("my.long.request.exception").longTaskTimer()
.activeTasks()).isEqualTo(0);
}
@Test
public void asyncCompletableFutureRequest() throws Exception {
AtomicReference<MvcResult> result = new AtomicReference<>();
Thread backgroundRequest = new Thread(() -> {
try {
result.set(this.mvc.perform(get("/api/c1/completableFuture/{id}", 1))
.andExpect(request().asyncStarted()).andReturn());
}
catch (Exception e) {
fail("Failed to execute async request", e);
}
});
backgroundRequest.start();
this.completableFutureBarrier.await();
MockClock.clock(this.registry).add(Duration.ofSeconds(2));
this.completableFutureBarrier.await();
backgroundRequest.join();
this.mvc.perform(asyncDispatch(result.get())).andExpect(status().isOk());
assertThat(this.registry.get("http.server.requests")
.tags("uri", "/api/c1/completableFuture/{id}").timer()
.totalTime(TimeUnit.SECONDS)).isEqualTo(2);
}
@Test
@@ -230,26 +306,32 @@ public class WebMvcMetricsFilterTests {
@Import({ Controller1.class, Controller2.class })
static class MetricsFilterApp {
@Bean
Clock micrometerClock() {
return new MockClock();
}
@Primary
@Bean
MeterRegistry meterRegistry(Collection<MeterRegistry> registries) {
CompositeMeterRegistry composite = new CompositeMeterRegistry();
MeterRegistry meterRegistry(Collection<MeterRegistry> registries, Clock clock) {
CompositeMeterRegistry composite = new CompositeMeterRegistry(clock);
registries.forEach(composite::add);
return composite;
}
@Bean
SimpleMeterRegistry simple() {
return new SimpleMeterRegistry();
SimpleMeterRegistry simple(Clock clock) {
return new SimpleMeterRegistry(SimpleConfig.DEFAULT, clock);
}
@Bean
PrometheusMeterRegistry prometheus() {
PrometheusMeterRegistry prometheus(Clock clock) {
PrometheusMeterRegistry r = new PrometheusMeterRegistry(
PrometheusConfig.DEFAULT, new CollectorRegistry(), Clock.SYSTEM);
PrometheusConfig.DEFAULT, new CollectorRegistry(), clock);
r.config().meterFilter(new MeterFilter() {
@Override
public MeterFilterReply accept(Meter.Id id) {
@NonNull
public MeterFilterReply accept(@NonNull Meter.Id id) {
for (Tag tag : id.getTags()) {
if (tag.getKey().equals("uri")
&& (tag.getValue().contains("histogram")
@@ -264,19 +346,25 @@ public class WebMvcMetricsFilterTests {
}
@Bean
CountDownLatch asyncLatch() {
return new CountDownLatch(1);
RedirectAndNotFoundFilter redirectAndNotFoundFilter() {
return new RedirectAndNotFoundFilter();
}
@Bean(name = "callableBarrier")
CyclicBarrier callableBarrier() {
return new CyclicBarrier(2);
}
@Bean(name = "completableFutureBarrier")
CyclicBarrier completableFutureBarrier() {
return new CyclicBarrier(2);
}
@Bean
public WebMvcMetrics controllerMetrics(MeterRegistry registry) {
return new WebMvcMetrics(registry, new DefaultWebMvcTagsProvider(),
"http.server.requests", true, false);
}
@Bean
public WebMvcMetricsFilter webMetricsFilter(ApplicationContext context) {
return new WebMvcMetricsFilter(context);
WebMvcMetricsFilter webMetricsFilter(MeterRegistry registry,
WebApplicationContext ctx) {
return new WebMvcMetricsFilter(ctx, registry, new DefaultWebMvcTagsProvider(),
"http.server.requests", true);
}
}
@@ -285,11 +373,13 @@ public class WebMvcMetricsFilterTests {
@RequestMapping("/api/c1")
static class Controller1 {
private final CountDownLatch asyncLatch;
@Autowired
@Qualifier("callableBarrier")
private CyclicBarrier callableBarrier;
Controller1(CountDownLatch asyncLatch) {
this.asyncLatch = asyncLatch;
}
@Autowired
@Qualifier("completableFutureBarrier")
private CyclicBarrier completableFutureBarrier;
@Timed(extraTags = { "public", "true" })
@GetMapping("/{id}")
@@ -300,19 +390,45 @@ public class WebMvcMetricsFilterTests {
@Timed
@Timed(value = "my.long.request", extraTags = { "region",
"test" }, longTask = true)
@GetMapping("/long/{id}")
public Callable<String> takesLongTimeToSatisfy(@PathVariable Long id) {
@GetMapping("/callable/{id}")
public Callable<String> asyncCallable(@PathVariable Long id) throws Exception {
this.callableBarrier.await();
return () -> {
try {
this.asyncLatch.await();
this.callableBarrier.await();
}
catch (InterruptedException e) {
throw new RuntimeException(e);
catch (InterruptedException ex) {
throw new RuntimeException(ex);
}
return id.toString();
};
}
@Timed
@GetMapping("/completableFuture/{id}")
CompletableFuture<String> asyncCompletableFuture(@PathVariable Long id)
throws Exception {
this.completableFutureBarrier.await();
return CompletableFuture.supplyAsync(() -> {
try {
this.completableFutureBarrier.await();
}
catch (InterruptedException | BrokenBarrierException ex) {
throw new RuntimeException(ex);
}
return id.toString();
});
}
@Timed
@Timed(value = "my.long.request.exception", longTask = true)
@GetMapping("/completableFutureException")
CompletableFuture<String> asyncCompletableFutureException() {
return CompletableFuture.supplyAsync(() -> {
throw new RuntimeException("boom");
});
}
@GetMapping("/untimed/{id}")
public String successfulButUntimed(@PathVariable Long id) {
return id.toString();

25
spring-boot-project/spring-boot-actuator/src/test/java/org/springframework/boot/actuate/metrics/web/servlet/WebMvcMetricsIntegrationTests.java
View File

@@ -27,11 +27,11 @@ import org.junit.Test;
import org.junit.runner.RunWith;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.context.ApplicationContext;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.http.HttpStatus;
import org.springframework.http.ResponseEntity;
import org.springframework.test.context.TestPropertySource;
import org.springframework.test.context.junit4.SpringRunner;
import org.springframework.test.context.web.WebAppConfiguration;
import org.springframework.test.web.servlet.MockMvc;
@@ -50,12 +50,13 @@ import static org.springframework.test.web.servlet.request.MockMvcRequestBuilder
import static org.springframework.test.web.servlet.result.MockMvcResultMatchers.status;
/**
* Integration tests for {@link WebMvcMetrics}.
* Tests for {@link WebMvcMetricsFilter} in the presence of a custom exception handler.
*
* @author Jon Schneider
*/
@RunWith(SpringRunner.class)
@WebAppConfiguration
@TestPropertySource(properties = "security.ignored=/**")
public class WebMvcMetricsIntegrationTests {
@Autowired
@@ -64,11 +65,11 @@ public class WebMvcMetricsIntegrationTests {
@Autowired
private SimpleMeterRegistry registry;
private MockMvc mvc;
@Autowired
private WebMvcMetricsFilter filter;
private MockMvc mvc;
@Before
public void setupMockMvc() {
this.mvc = MockMvcBuilders.webAppContextSetup(this.context)
@@ -107,14 +108,10 @@ public class WebMvcMetricsIntegrationTests {
}
@Bean
public WebMvcMetrics controllerMetrics(MeterRegistry registry) {
return new WebMvcMetrics(registry, new DefaultWebMvcTagsProvider(),
"http.server.requests", true, false);
}
@Bean
public WebMvcMetricsFilter webMetricsFilter(ApplicationContext context) {
return new WebMvcMetricsFilter(context);
public WebMvcMetricsFilter webMetricsFilter(MeterRegistry registry,
WebApplicationContext ctx) {
return new WebMvcMetricsFilter(ctx, registry, new DefaultWebMvcTagsProvider(),
"http.server.requests", true);
}
@RestController
@@ -152,12 +149,8 @@ public class WebMvcMetricsIntegrationTests {
@ControllerAdvice
static class CustomExceptionHandler {
@Autowired
WebMvcMetrics metrics;
@ExceptionHandler
ResponseEntity<String> handleError(Exception1 ex) {
this.metrics.tagWithException(ex);
return new ResponseEntity<>("this is a custom exception body",
HttpStatus.INTERNAL_SERVER_ERROR);
}