Merge branch '2.4.x'

Closes gh-26596

Author: wilkinsona

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

@@ -23,6 +23,8 @@
 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 @@
 @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 @@ private void onTerminalSignal(ServerWebExchange exchange, Throwable cause, long
 	}
 
 	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) {

spring-boot-project/spring-boot-actuator/src/main/java/org/springframework/boot/actuate/metrics/web/servlet/LongTaskTimingHandlerInterceptor.java

@@ -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.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 @@
  */
 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 @@ private void startAndAttachTimingContext(HttpServletRequest request, Object hand
 	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;
 	}
 

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

@@ -30,6 +30,8 @@
 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 @@
  */
 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 @@ private Throwable fetchException(HttpServletRequest request) {
 
 	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) {

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

@@ -18,9 +18,11 @@
 
 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.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 @@ void filterAddsPercentileMeters() {
 		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 @@ Mono<String> timedPercentiles() {
 
 	}
 
+	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);
+		}
+
+	}
+
 }

spring-boot-project/spring-boot-actuator/src/test/java/org/springframework/boot/actuate/metrics/web/servlet/FaultyWebMvcTagsProvider.java

@@ -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);
+	}
+
+}

spring-boot-project/spring-boot-actuator/src/test/java/org/springframework/boot/actuate/metrics/web/servlet/LongTaskTimingHandlerInterceptorTests.java

@@ -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 @@
 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 @@ void asyncCallableRequest() throws Exception {
 				.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 @@ CyclicBarrier callableBarrier() {
 		}
 
 		@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));
 				}
 
 			};

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

@@ -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 @@ void streamingError() throws Exception {
 				.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 @@ CyclicBarrier completableFutureBarrier() {
 		}
 
 		@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();
 		}
 
 	}