Merge branch '2.4.x'

Closes gh-26596
This commit is contained in:
Andy Wilkinson 2021-05-19 13:38:20 +01:00
commit b9abcba778
7 changed files with 195 additions and 27 deletions

View File

@ -23,6 +23,8 @@ import java.util.concurrent.TimeUnit;
import io.micrometer.core.annotation.Timed;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Tag;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.reactivestreams.Publisher;
import reactor.core.publisher.Mono;
@ -49,6 +51,8 @@ import org.springframework.web.server.WebFilterChain;
@Order(Ordered.HIGHEST_PRECEDENCE + 1)
public class MetricsWebFilter implements WebFilter {
private static Log logger = LogFactory.getLog(MetricsWebFilter.class);
private final MeterRegistry registry;
private final WebFluxTagsProvider tagsProvider;
@ -98,13 +102,19 @@ public class MetricsWebFilter implements WebFilter {
}
private void record(ServerWebExchange exchange, Throwable cause, long start) {
cause = (cause != null) ? cause : exchange.getAttribute(ErrorAttributes.ERROR_ATTRIBUTE);
Object handler = exchange.getAttribute(HandlerMapping.BEST_MATCHING_HANDLER_ATTRIBUTE);
Set<Timed> annotations = getTimedAnnotations(handler);
Iterable<Tag> tags = this.tagsProvider.httpRequestTags(exchange, cause);
long duration = System.nanoTime() - start;
AutoTimer.apply(this.autoTimer, this.metricName, annotations,
(builder) -> builder.tags(tags).register(this.registry).record(duration, TimeUnit.NANOSECONDS));
try {
cause = (cause != null) ? cause : exchange.getAttribute(ErrorAttributes.ERROR_ATTRIBUTE);
Object handler = exchange.getAttribute(HandlerMapping.BEST_MATCHING_HANDLER_ATTRIBUTE);
Set<Timed> annotations = getTimedAnnotations(handler);
Iterable<Tag> tags = this.tagsProvider.httpRequestTags(exchange, cause);
long duration = System.nanoTime() - start;
AutoTimer.apply(this.autoTimer, this.metricName, annotations,
(builder) -> builder.tags(tags).register(this.registry).record(duration, TimeUnit.NANOSECONDS));
}
catch (Exception ex) {
logger.warn("Failed to record timer metrics", ex);
// Allow exchange to continue, unaffected by metrics problem
}
}
private Set<Timed> getTimedAnnotations(Object handler) {

View File

@ -1,5 +1,5 @@
/*
* Copyright 2012-2019 the original author or authors.
* Copyright 2012-2021 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.
@ -30,6 +30,8 @@ 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 org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.springframework.core.annotation.MergedAnnotationCollectors;
import org.springframework.core.annotation.MergedAnnotations;
@ -46,6 +48,8 @@ import org.springframework.web.servlet.HandlerInterceptor;
*/
public class LongTaskTimingHandlerInterceptor implements HandlerInterceptor {
private static final Log logger = LogFactory.getLog(LongTaskTimingHandlerInterceptor.class);
private final MeterRegistry registry;
private final WebMvcTagsProvider tagsProvider;
@ -90,12 +94,18 @@ public class LongTaskTimingHandlerInterceptor implements HandlerInterceptor {
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());
});
try {
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());
});
}
catch (Exception ex) {
logger.warn("Failed to start long task timers", ex);
// Allow request-response exchange to continue, unaffected by metrics problem
}
return samples;
}

View File

@ -30,6 +30,8 @@ import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Timer;
import io.micrometer.core.instrument.Timer.Builder;
import io.micrometer.core.instrument.Timer.Sample;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.springframework.boot.actuate.metrics.AutoTimer;
import org.springframework.boot.actuate.metrics.annotation.TimedAnnotations;
@ -52,6 +54,8 @@ import org.springframework.web.util.NestedServletException;
*/
public class WebMvcMetricsFilter extends OncePerRequestFilter {
private static final Log logger = LogFactory.getLog(WebMvcMetricsFilter.class);
private final MeterRegistry registry;
private final WebMvcTagsProvider tagsProvider;
@ -127,11 +131,17 @@ public class WebMvcMetricsFilter extends OncePerRequestFilter {
private void record(TimingContext timingContext, HttpServletRequest request, HttpServletResponse response,
Throwable exception) {
Object handler = getHandler(request);
Set<Timed> annotations = getTimedAnnotations(handler);
Timer.Sample timerSample = timingContext.getTimerSample();
AutoTimer.apply(this.autoTimer, this.metricName, annotations,
(builder) -> timerSample.stop(getTimer(builder, handler, request, response, exception)));
try {
Object handler = getHandler(request);
Set<Timed> annotations = getTimedAnnotations(handler);
Timer.Sample timerSample = timingContext.getTimerSample();
AutoTimer.apply(this.autoTimer, this.metricName, annotations,
(builder) -> timerSample.stop(getTimer(builder, handler, request, response, exception)));
}
catch (Exception ex) {
logger.warn("Failed to record timer metrics", ex);
// Allow request-response exchange to continue, unaffected by metrics problem
}
}
private Object getHandler(HttpServletRequest request) {

View File

@ -18,9 +18,11 @@ package org.springframework.boot.actuate.metrics.web.reactive.server;
import java.io.EOFException;
import java.time.Duration;
import java.util.concurrent.atomic.AtomicBoolean;
import io.micrometer.core.annotation.Timed;
import io.micrometer.core.instrument.MockClock;
import io.micrometer.core.instrument.Tag;
import io.micrometer.core.instrument.simple.SimpleConfig;
import io.micrometer.core.instrument.simple.SimpleMeterRegistry;
import org.junit.jupiter.api.BeforeEach;
@ -35,6 +37,7 @@ import org.springframework.mock.web.server.MockServerWebExchange;
import org.springframework.util.ReflectionUtils;
import org.springframework.web.method.HandlerMethod;
import org.springframework.web.reactive.HandlerMapping;
import org.springframework.web.server.ServerWebExchange;
import org.springframework.web.util.pattern.PathPatternParser;
import static org.assertj.core.api.Assertions.assertThat;
@ -51,6 +54,8 @@ class MetricsWebFilterTests {
private static final String REQUEST_METRICS_NAME_PERCENTILE = REQUEST_METRICS_NAME + ".percentile";
private final FaultyWebFluxTagsProvider tagsProvider = new FaultyWebFluxTagsProvider();
private SimpleMeterRegistry registry;
private MetricsWebFilter webFilter;
@ -59,7 +64,7 @@ class MetricsWebFilterTests {
void setup() {
MockClock clock = new MockClock();
this.registry = new SimpleMeterRegistry(SimpleConfig.DEFAULT, clock);
this.webFilter = new MetricsWebFilter(this.registry, new DefaultWebFluxTagsProvider(true), REQUEST_METRICS_NAME,
this.webFilter = new MetricsWebFilter(this.registry, this.tagsProvider, REQUEST_METRICS_NAME,
AutoTimer.ENABLED);
}
@ -208,6 +213,14 @@ class MetricsWebFilterTests {
assertThat(this.registry.get(REQUEST_METRICS_NAME_PERCENTILE).tag("phi", "0.5").gauge().value()).isNotZero();
}
@Test
void whenMetricsRecordingFailsThenExchangeFilteringSucceeds() {
MockServerWebExchange exchange = createExchange("/projects/spring-boot", "/projects/{project}");
this.tagsProvider.failOnce();
this.webFilter.filter(exchange, (serverWebExchange) -> exchange.getResponse().setComplete())
.block(Duration.ofSeconds(30));
}
private MockServerWebExchange createTimedHandlerMethodExchange(String methodName) {
MockServerWebExchange exchange = createExchange("/projects/spring-boot", "/projects/{project}");
exchange.getAttributes().put(HandlerMapping.BEST_MATCHING_HANDLER_ATTRIBUTE,
@ -245,4 +258,26 @@ class MetricsWebFilterTests {
}
class FaultyWebFluxTagsProvider extends DefaultWebFluxTagsProvider {
private volatile AtomicBoolean fail = new AtomicBoolean(false);
FaultyWebFluxTagsProvider() {
super(true);
}
@Override
public Iterable<Tag> httpRequestTags(ServerWebExchange exchange, Throwable exception) {
if (this.fail.compareAndSet(true, false)) {
throw new RuntimeException();
}
return super.httpRequestTags(exchange, exception);
}
void failOnce() {
this.fail.set(true);
}
}
}

View File

@ -0,0 +1,61 @@
/*
* Copyright 2012-2021 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
*
* https://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.util.concurrent.atomic.AtomicBoolean;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import io.micrometer.core.instrument.Tag;
/**
* {@link WebMvcTagsProvider} used for testing that can be configured to fail when getting
* tags or long task tags.
*
* @author Andy Wilkinson
*/
class FaultyWebMvcTagsProvider extends DefaultWebMvcTagsProvider {
private volatile AtomicBoolean fail = new AtomicBoolean(false);
FaultyWebMvcTagsProvider() {
super(true);
}
@Override
public Iterable<Tag> getTags(HttpServletRequest request, HttpServletResponse response, Object handler,
Throwable exception) {
if (this.fail.compareAndSet(true, false)) {
throw new RuntimeException();
}
return super.getTags(request, response, handler, exception);
}
@Override
public Iterable<Tag> getLongRequestTags(HttpServletRequest request, Object handler) {
if (this.fail.compareAndSet(true, false)) {
throw new RuntimeException();
}
return super.getLongRequestTags(request, handler);
}
void failOnce() {
this.fail.set(true);
}
}

View File

@ -1,5 +1,5 @@
/*
* Copyright 2012-2019 the original author or authors.
* Copyright 2012-2021 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.
@ -19,6 +19,7 @@ package org.springframework.boot.actuate.metrics.web.servlet;
import java.util.concurrent.Callable;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.CyclicBarrier;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicReference;
import io.micrometer.core.annotation.Timed;
@ -76,6 +77,9 @@ class LongTaskTimingHandlerInterceptorTests {
@Autowired
private CyclicBarrier callableBarrier;
@Autowired
private FaultyWebMvcTagsProvider tagsProvider;
private MockMvc mvc;
@BeforeEach
@ -117,6 +121,26 @@ class LongTaskTimingHandlerInterceptorTests {
.isEqualTo(0);
}
@Test
void whenMetricsRecordingFailsResponseIsUnaffected() throws Exception {
this.tagsProvider.failOnce();
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();
this.callableBarrier.await(10, TimeUnit.SECONDS);
this.callableBarrier.await(10, TimeUnit.SECONDS);
backgroundRequest.join();
this.mvc.perform(asyncDispatch(result.get())).andExpect(status().isOk());
}
@Configuration(proxyBeanMethods = false)
@EnableWebMvc
@Import(Controller1.class)
@ -138,13 +162,17 @@ class LongTaskTimingHandlerInterceptorTests {
}
@Bean
WebMvcConfigurer handlerInterceptorConfigurer(MeterRegistry meterRegistry) {
FaultyWebMvcTagsProvider webMvcTagsProvider() {
return new FaultyWebMvcTagsProvider();
}
@Bean
WebMvcConfigurer handlerInterceptorConfigurer(MeterRegistry meterRegistry, WebMvcTagsProvider tagsProvider) {
return new WebMvcConfigurer() {
@Override
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(
new LongTaskTimingHandlerInterceptor(meterRegistry, new DefaultWebMvcTagsProvider()));
registry.addInterceptor(new LongTaskTimingHandlerInterceptor(meterRegistry, tagsProvider));
}
};

View File

@ -122,6 +122,9 @@ class WebMvcMetricsFilterTests {
@Qualifier("completableFutureBarrier")
private CyclicBarrier completableFutureBarrier;
@Autowired
private FaultyWebMvcTagsProvider tagsProvider;
@BeforeEach
void setupMockMvc() {
this.mvc = MockMvcBuilders.webAppContextSetup(this.context)
@ -193,6 +196,12 @@ class WebMvcMetricsFilterTests {
.isEqualTo(1L);
}
@Test
void whenMetricsRecordingFailsResponseIsUnaffected() throws Exception {
this.tagsProvider.failOnce();
this.mvc.perform(get("/api/c1/10")).andExpect(status().isOk());
}
@Test
void anonymousError() {
try {
@ -365,9 +374,14 @@ class WebMvcMetricsFilterTests {
}
@Bean
WebMvcMetricsFilter webMetricsFilter(MeterRegistry registry, WebApplicationContext ctx) {
return new WebMvcMetricsFilter(registry, new DefaultWebMvcTagsProvider(true), "http.server.requests",
AutoTimer.ENABLED);
WebMvcMetricsFilter webMetricsFilter(MeterRegistry registry, FaultyWebMvcTagsProvider tagsProvider,
WebApplicationContext ctx) {
return new WebMvcMetricsFilter(registry, tagsProvider, "http.server.requests", AutoTimer.ENABLED);
}
@Bean
FaultyWebMvcTagsProvider faultyWebMvcTagsProvider() {
return new FaultyWebMvcTagsProvider();
}
}