Log unhandled server exceptions in WebFlux

Prior to this commit, errors unhandled by custom `WebExceptionHandler`
and resulting in an HTTP 500 status would not be logged at ERROR level,
giving no information to developers about the actual exception.

This commit ensures that such exceptions are logged at the ERROR level
with their exception. By the time the exception hits the
`DefaultErrorWebExceptionHandler`, if the response is already committed
or if the exception is due to a client disconnecting, the error is
delegated to Framework support as Spring Boot won't be able to render an
error page as expected.

Fixes gh-15769

spring-boot-project/spring-boot-autoconfigure/src/main/java/org/springframework/boot/autoconfigure/web/reactive/error/AbstractErrorWebExceptionHandler.java

 /*
- * Copyright 2012-2018 the original author or authors.
+ * Copyright 2012-2019 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,11 +16,15 @@
 
 package org.springframework.boot.autoconfigure.web.reactive.error;
 
+import java.util.Arrays;
 import java.util.Collections;
 import java.util.Date;
+import java.util.HashSet;
 import java.util.List;
 import java.util.Map;
+import java.util.Set;
 
+import org.apache.commons.logging.Log;
 import reactor.core.publisher.Mono;
 
 import org.springframework.beans.factory.InitializingBean;
@@ -29,11 +33,15 @@ import org.springframework.boot.autoconfigure.web.ResourceProperties;
 import org.springframework.boot.web.reactive.error.ErrorAttributes;
 import org.springframework.boot.web.reactive.error.ErrorWebExceptionHandler;
 import org.springframework.context.ApplicationContext;
+import org.springframework.core.NestedExceptionUtils;
 import org.springframework.core.io.Resource;
+import org.springframework.http.HttpLogging;
+import org.springframework.http.HttpStatus;
 import org.springframework.http.codec.HttpMessageReader;
 import org.springframework.http.codec.HttpMessageWriter;
 import org.springframework.util.Assert;
 import org.springframework.util.CollectionUtils;
+import org.springframework.util.StringUtils;
 import org.springframework.web.reactive.function.BodyInserters;
 import org.springframework.web.reactive.function.server.RouterFunction;
 import org.springframework.web.reactive.function.server.ServerRequest;
@@ -52,6 +60,15 @@ import org.springframework.web.util.HtmlUtils;
 public abstract class AbstractErrorWebExceptionHandler
 		implements ErrorWebExceptionHandler, InitializingBean {
 
+	/**
+	 * Currently duplicated from Spring WebFlux HttpWebHandlerAdapter.
+	 */
+	private static final Set<String> DISCONNECTED_CLIENT_EXCEPTIONS = new HashSet<>(
+			Arrays.asList("ClientAbortException", "EOFException", "EofException"));
+
+	private static final Log logger = HttpLogging
+			.forLogName(AbstractErrorWebExceptionHandler.class);
+
 	private final ApplicationContext applicationContext;
 
 	private final ErrorAttributes errorAttributes;
@@ -236,7 +253,8 @@ public abstract class AbstractErrorWebExceptionHandler
 
 	@Override
 	public Mono<Void> handle(ServerWebExchange exchange, Throwable throwable) {
-		if (exchange.getResponse().isCommitted()) {
+		if (exchange.getResponse().isCommitted()
+				|| isDisconnectedClientError(throwable)) {
 			return Mono.error(throwable);
 		}
 		this.errorAttributes.storeErrorInformation(throwable, exchange);
@@ -244,9 +262,42 @@ public abstract class AbstractErrorWebExceptionHandler
 		return getRoutingFunction(this.errorAttributes).route(request)
 				.switchIfEmpty(Mono.error(throwable))
 				.flatMap((handler) -> handler.handle(request))
+				.doOnNext((response) -> logError(request, response, throwable))
 				.flatMap((response) -> write(exchange, response));
 	}
 
+	private boolean isDisconnectedClientError(Throwable ex) {
+		String message = NestedExceptionUtils.getMostSpecificCause(ex).getMessage();
+		message = (message != null) ? message.toLowerCase() : "";
+		String className = ex.getClass().getSimpleName();
+		return (message.contains("broken pipe")
+				|| DISCONNECTED_CLIENT_EXCEPTIONS.contains(className));
+	}
+
+	private void logError(ServerRequest request, ServerResponse response,
+			Throwable throwable) {
+		if (logger.isDebugEnabled()) {
+			logger.debug(
+					request.exchange().getLogPrefix() + formatError(throwable, request));
+		}
+		if (response.statusCode().equals(HttpStatus.INTERNAL_SERVER_ERROR)) {
+			logger.error(request.exchange().getLogPrefix() + "500 Server Error for "
+					+ formatRequest(request), throwable);
+		}
+	}
+
+	private String formatError(Throwable ex, ServerRequest request) {
+		String reason = ex.getClass().getSimpleName() + ": " + ex.getMessage();
+		return "Resolved [" + reason + "] for HTTP " + request.methodName() + " "
+				+ request.path();
+	}
+
+	private String formatRequest(ServerRequest request) {
+		String rawQuery = request.uri().getRawQuery();
+		String query = StringUtils.hasText(rawQuery) ? "?" + rawQuery : "";
+		return "HTTP " + request.methodName() + " \"" + request.path() + query + "\"";
+	}
+
 	private Mono<? extends Void> write(ServerWebExchange exchange,
 			ServerResponse response) {
 		// force content-type since writeTo won't overwrite response header values

spring-boot-project/spring-boot-autoconfigure/src/main/java/org/springframework/boot/autoconfigure/web/reactive/error/DefaultErrorWebExceptionHandler.java

 /*
- * Copyright 2012-2018 the original author or authors.
+ * Copyright 2012-2019 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.
@@ -21,7 +21,6 @@ import java.util.EnumMap;
 import java.util.List;
 import java.util.Map;
 
-import org.apache.commons.logging.Log;
 import reactor.core.publisher.Flux;
 import reactor.core.publisher.Mono;
 
@@ -29,7 +28,6 @@ import org.springframework.boot.autoconfigure.web.ErrorProperties;
 import org.springframework.boot.autoconfigure.web.ResourceProperties;
 import org.springframework.boot.web.reactive.error.ErrorAttributes;
 import org.springframework.context.ApplicationContext;
-import org.springframework.http.HttpLogging;
 import org.springframework.http.HttpStatus;
 import org.springframework.http.InvalidMediaTypeException;
 import org.springframework.http.MediaType;
@@ -77,9 +75,6 @@ public class DefaultErrorWebExceptionHandler extends AbstractErrorWebExceptionHa
 
 	private static final Map<HttpStatus.Series, String> SERIES_VIEWS;
 
-	private static final Log logger = HttpLogging
-			.forLogName(DefaultErrorWebExceptionHandler.class);
-
 	static {
 		Map<HttpStatus.Series, String> views = new EnumMap<>(HttpStatus.Series.class);
 		views.put(HttpStatus.Series.CLIENT_ERROR, "4xx");
@@ -128,7 +123,7 @@ public class DefaultErrorWebExceptionHandler extends AbstractErrorWebExceptionHa
 				.switchIfEmpty(this.errorProperties.getWhitelabel().isEnabled()
 						? renderDefaultErrorView(responseBody, error)
 						: Mono.error(getError(request)))
-				.next().doOnNext((response) -> logError(request, errorStatus));
+				.next();
 	}
 
 	/**
@@ -142,8 +137,7 @@ public class DefaultErrorWebExceptionHandler extends AbstractErrorWebExceptionHa
 		HttpStatus errorStatus = getHttpStatus(error);
 		return ServerResponse.status(getHttpStatus(error))
 				.contentType(MediaType.APPLICATION_JSON_UTF8)
-				.body(BodyInserters.fromObject(error))
-				.doOnNext((resp) -> logError(request, errorStatus));
+				.body(BodyInserters.fromObject(error));
 	}
 
 	/**
@@ -196,23 +190,4 @@ public class DefaultErrorWebExceptionHandler extends AbstractErrorWebExceptionHa
 		};
 	}
 
-	/**
-	 * Log the original exception if handling it results in a Server Error or a Bad
-	 * Request (Client Error with 400 status code) one.
-	 * @param request the source request
-	 * @param errorStatus the HTTP error status
-	 */
-	protected void logError(ServerRequest request, HttpStatus errorStatus) {
-		Throwable ex = getError(request);
-		if (logger.isDebugEnabled()) {
-			logger.debug(request.exchange().getLogPrefix() + formatError(ex, request));
-		}
-	}
-
-	private String formatError(Throwable ex, ServerRequest request) {
-		String reason = ex.getClass().getSimpleName() + ": " + ex.getMessage();
-		return "Resolved [" + reason + "] for HTTP " + request.methodName() + " "
-				+ request.path();
-	}
-
 }

spring-boot-project/spring-boot-autoconfigure/src/test/java/org/springframework/boot/autoconfigure/web/reactive/error/DefaultErrorWebExceptionHandlerIntegrationTests.java

 /*
- * Copyright 2012-2018 the original author or authors.
+ * Copyright 2012-2019 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.
@@ -18,6 +18,8 @@ package org.springframework.boot.autoconfigure.web.reactive.error;
 
 import javax.validation.Valid;
 
+import org.hamcrest.Matchers;
+import org.junit.Rule;
 import org.junit.Test;
 import reactor.core.publisher.Mono;
 
@@ -28,6 +30,7 @@ import org.springframework.boot.autoconfigure.web.reactive.HttpHandlerAutoConfig
 import org.springframework.boot.autoconfigure.web.reactive.ReactiveWebServerFactoryAutoConfiguration;
 import org.springframework.boot.autoconfigure.web.reactive.WebFluxAutoConfiguration;
 import org.springframework.boot.test.context.runner.ReactiveWebApplicationContextRunner;
+import org.springframework.boot.testsupport.rule.OutputCapture;
 import org.springframework.context.annotation.Configuration;
 import org.springframework.http.HttpStatus;
 import org.springframework.http.MediaType;
@@ -42,6 +45,7 @@ import org.springframework.web.server.ServerWebExchange;
 
 import static org.assertj.core.api.Assertions.assertThat;
 import static org.assertj.core.api.Assertions.assertThatExceptionOfType;
+import static org.hamcrest.Matchers.containsString;
 
 /**
  * Integration tests for {@link DefaultErrorWebExceptionHandler}
@@ -50,6 +54,9 @@ import static org.assertj.core.api.Assertions.assertThatExceptionOfType;
  */
 public class DefaultErrorWebExceptionHandlerIntegrationTests {
 
+	@Rule
+	public OutputCapture outputCapture = new OutputCapture();
+
 	private ReactiveWebApplicationContextRunner contextRunner = new ReactiveWebApplicationContextRunner()
 			.withConfiguration(AutoConfigurations.of(
 					ReactiveWebServerFactoryAutoConfiguration.class,
@@ -73,6 +80,9 @@ public class DefaultErrorWebExceptionHandlerIntegrationTests {
 					.jsonPath("path").isEqualTo(("/")).jsonPath("message")
 					.isEqualTo("Expected!").jsonPath("exception").doesNotExist()
 					.jsonPath("trace").doesNotExist();
+			this.outputCapture.expect(Matchers.allOf(
+					containsString("500 Server Error for HTTP GET \"/\""),
+					containsString("java.lang.IllegalStateException: Expected!")));
 		});
 	}
 
@@ -98,6 +108,9 @@ public class DefaultErrorWebExceptionHandlerIntegrationTests {
 					.expectHeader().contentType(MediaType.TEXT_HTML)
 					.expectBody(String.class).returnResult().getResponseBody();
 			assertThat(body).contains("status: 500").contains("message: Expected!");
+			this.outputCapture.expect(Matchers.allOf(
+					containsString("500 Server Error for HTTP GET \"/\""),
+					containsString("java.lang.IllegalStateException: Expected!")));
 		});
 	}