root
/
spring-boot
mirror of https://github.com/spring-projects/spring-boot.git
1
0
Fork 0
Code Issues Actions 12 Packages Projects Releases Wiki Activity

Prevent metrics failures from adversely affecting web responses 

Fixes gh-24151
This commit is contained in:
Andy Wilkinson 2021-05-19 13:13:35 +01:00
parent 678916fb3d
commit 936c31c7a7
7 changed files with 202 additions and 34 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

18
spring-boot-project/spring-boot-actuator/src/main/java/org/springframework/boot/actuate/metrics/web/reactive/server/MetricsWebFilter.java
View File

@ -1,5 +1,5 @@
/*
* Copyright 2012-2020 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.
@ -20,6 +20,8 @@ import java.util.concurrent.TimeUnit;
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;
@ -41,6 +43,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;
@ -97,9 +101,15 @@ public class MetricsWebFilter implements WebFilter {
}
private void record(ServerWebExchange exchange, long start, Throwable cause) {
Iterable<Tag> tags = this.tagsProvider.httpRequestTags(exchange, cause);
this.autoTimer.builder(this.metricName).tags(tags).register(this.registry).record(System.nanoTime() - start,
TimeUnit.NANOSECONDS);
try {
Iterable<Tag> tags = this.tagsProvider.httpRequestTags(exchange, cause);
this.autoTimer.builder(this.metricName).tags(tags).register(this.registry).record(System.nanoTime() - start,
TimeUnit.NANOSECONDS);
}
catch (Exception ex) {
logger.warn("Failed to record timer metrics", ex);
// Allow exchange to continue, unaffected by metrics problem
}
}
}

24
spring-boot-project/spring-boot-actuator/src/main/java/org/springframework/boot/actuate/metrics/web/servlet/LongTaskTimingHandlerInterceptor.java
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;
}

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

@ -1,5 +1,5 @@
/*
* Copyright 2012-2020 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.
@ -31,6 +31,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.core.annotation.MergedAnnotationCollectors;
@ -53,6 +55,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;
@ -120,20 +124,26 @@ 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();
if (annotations.isEmpty()) {
if (this.autoTimer.isEnabled()) {
Builder builder = this.autoTimer.builder(this.metricName);
timerSample.stop(getTimer(builder, handler, request, response, exception));
try {
Object handler = getHandler(request);
Set<Timed> annotations = getTimedAnnotations(handler);
Timer.Sample timerSample = timingContext.getTimerSample();
if (annotations.isEmpty()) {
if (this.autoTimer.isEnabled()) {
Builder builder = this.autoTimer.builder(this.metricName);
timerSample.stop(getTimer(builder, handler, request, response, exception));
}
}
else {
for (Timed annotation : annotations) {
Builder builder = Timer.builder(annotation, this.metricName);
timerSample.stop(getTimer(builder, handler, request, response, exception));
}
}
}
else {
for (Timed annotation : annotations) {
Builder builder = Timer.builder(annotation, this.metricName);
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
}
}

39
spring-boot-project/spring-boot-actuator/src/test/java/org/springframework/boot/actuate/metrics/web/reactive/server/MetricsWebFilterTests.java
View File

@ -1,5 +1,5 @@
/*
* Copyright 2012-2020 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.
@ -17,8 +17,10 @@
package org.springframework.boot.actuate.metrics.web.reactive.server;
import java.time.Duration;
import java.util.concurrent.atomic.AtomicBoolean;
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;
@ -29,6 +31,7 @@ import org.springframework.boot.actuate.metrics.AutoTimer;
import org.springframework.mock.http.server.reactive.MockServerHttpRequest;
import org.springframework.mock.web.server.MockServerWebExchange;
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;
@ -43,6 +46,8 @@ class MetricsWebFilterTests {
private static final String REQUEST_METRICS_NAME = "http.server.requests";
private final FaultyWebFluxTagsProvider tagsProvider = new FaultyWebFluxTagsProvider();
private SimpleMeterRegistry registry;
private MetricsWebFilter webFilter;
@ -51,7 +56,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);
}
@ -116,6 +121,14 @@ class MetricsWebFilterTests {
assertThat(this.registry.get(REQUEST_METRICS_NAME).tag("status", "200").timer().count()).isEqualTo(2);
}
@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 createExchange(String path, String pathPattern) {
PathPatternParser parser = new PathPatternParser();
MockServerWebExchange exchange = MockServerWebExchange.from(MockServerHttpRequest.get(path).build());
@ -127,4 +140,26 @@ class MetricsWebFilterTests {
assertThat(this.registry.get(REQUEST_METRICS_NAME).tag(tagKey, tagValue).timer().count()).isEqualTo(1);
}
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);
}
}
}

61
spring-boot-project/spring-boot-actuator/src/test/java/org/springframework/boot/actuate/metrics/web/servlet/FaultyWebMvcTagsProvider.java Normal file
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);
}
}

36
spring-boot-project/spring-boot-actuator/src/test/java/org/springframework/boot/actuate/metrics/web/servlet/LongTaskTimingHandlerInterceptorTests.java
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));
}
};

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

@ -1,5 +1,5 @@
/*
* Copyright 2012-2020 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.
@ -121,6 +121,9 @@ class WebMvcMetricsFilterTests {
@Qualifier("completableFutureBarrier")
private CyclicBarrier completableFutureBarrier;
@Autowired
private FaultyWebMvcTagsProvider tagsProvider;
@BeforeEach
void setupMockMvc() {
this.mvc = MockMvcBuilders.webAppContextSetup(this.context)
@ -192,6 +195,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 {
@ -363,9 +372,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();
}
}