Skip to content

Commit cba6079

Browse files
bclozelbclozel
committed
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 spring-projectsgh-15769
1 parent 64cb4e2 commit cba6079

File tree

3 files changed

+70
-31
lines changed

3 files changed

+70
-31
lines changed

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

+53-2
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
/*
2-
* Copyright 2012-2018 the original author or authors.
2+
* Copyright 2012-2019 the original author or authors.
33
*
44
* Licensed under the Apache License, Version 2.0 (the "License");
55
* you may not use this file except in compliance with the License.
@@ -16,11 +16,15 @@
1616

1717
package org.springframework.boot.autoconfigure.web.reactive.error;
1818

19+
import java.util.Arrays;
1920
import java.util.Collections;
2021
import java.util.Date;
22+
import java.util.HashSet;
2123
import java.util.List;
2224
import java.util.Map;
25+
import java.util.Set;
2326

27+
import org.apache.commons.logging.Log;
2428
import reactor.core.publisher.Mono;
2529

2630
import org.springframework.beans.factory.InitializingBean;
@@ -29,11 +33,15 @@
2933
import org.springframework.boot.web.reactive.error.ErrorAttributes;
3034
import org.springframework.boot.web.reactive.error.ErrorWebExceptionHandler;
3135
import org.springframework.context.ApplicationContext;
36+
import org.springframework.core.NestedExceptionUtils;
3237
import org.springframework.core.io.Resource;
38+
import org.springframework.http.HttpLogging;
39+
import org.springframework.http.HttpStatus;
3340
import org.springframework.http.codec.HttpMessageReader;
3441
import org.springframework.http.codec.HttpMessageWriter;
3542
import org.springframework.util.Assert;
3643
import org.springframework.util.CollectionUtils;
44+
import org.springframework.util.StringUtils;
3745
import org.springframework.web.reactive.function.BodyInserters;
3846
import org.springframework.web.reactive.function.server.RouterFunction;
3947
import org.springframework.web.reactive.function.server.ServerRequest;
@@ -52,6 +60,15 @@
5260
public abstract class AbstractErrorWebExceptionHandler
5361
implements ErrorWebExceptionHandler, InitializingBean {
5462

63+
/**
64+
* Currently duplicated from Spring WebFlux HttpWebHandlerAdapter.
65+
*/
66+
private static final Set<String> DISCONNECTED_CLIENT_EXCEPTIONS = new HashSet<>(
67+
Arrays.asList("ClientAbortException", "EOFException", "EofException"));
68+
69+
private static final Log logger = HttpLogging
70+
.forLogName(AbstractErrorWebExceptionHandler.class);
71+
5572
private final ApplicationContext applicationContext;
5673

5774
private final ErrorAttributes errorAttributes;
@@ -236,17 +253,51 @@ protected abstract RouterFunction<ServerResponse> getRoutingFunction(
236253

237254
@Override
238255
public Mono<Void> handle(ServerWebExchange exchange, Throwable throwable) {
239-
if (exchange.getResponse().isCommitted()) {
256+
if (exchange.getResponse().isCommitted()
257+
|| isDisconnectedClientError(throwable)) {
240258
return Mono.error(throwable);
241259
}
242260
this.errorAttributes.storeErrorInformation(throwable, exchange);
243261
ServerRequest request = ServerRequest.create(exchange, this.messageReaders);
244262
return getRoutingFunction(this.errorAttributes).route(request)
245263
.switchIfEmpty(Mono.error(throwable))
246264
.flatMap((handler) -> handler.handle(request))
265+
.doOnNext((response) -> logError(request, response, throwable))
247266
.flatMap((response) -> write(exchange, response));
248267
}
249268

269+
private boolean isDisconnectedClientError(Throwable ex) {
270+
String message = NestedExceptionUtils.getMostSpecificCause(ex).getMessage();
271+
message = (message != null) ? message.toLowerCase() : "";
272+
String className = ex.getClass().getSimpleName();
273+
return (message.contains("broken pipe")
274+
|| DISCONNECTED_CLIENT_EXCEPTIONS.contains(className));
275+
}
276+
277+
private void logError(ServerRequest request, ServerResponse response,
278+
Throwable throwable) {
279+
if (logger.isDebugEnabled()) {
280+
logger.debug(
281+
request.exchange().getLogPrefix() + formatError(throwable, request));
282+
}
283+
if (response.statusCode().equals(HttpStatus.INTERNAL_SERVER_ERROR)) {
284+
logger.error(request.exchange().getLogPrefix() + "500 Server Error for "
285+
+ formatRequest(request), throwable);
286+
}
287+
}
288+
289+
private String formatError(Throwable ex, ServerRequest request) {
290+
String reason = ex.getClass().getSimpleName() + ": " + ex.getMessage();
291+
return "Resolved [" + reason + "] for HTTP " + request.methodName() + " "
292+
+ request.path();
293+
}
294+
295+
private String formatRequest(ServerRequest request) {
296+
String rawQuery = request.uri().getRawQuery();
297+
String query = StringUtils.hasText(rawQuery) ? "?" + rawQuery : "";
298+
return "HTTP " + request.methodName() + " \"" + request.path() + query + "\"";
299+
}
300+
250301
private Mono<? extends Void> write(ServerWebExchange exchange,
251302
ServerResponse response) {
252303
// 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

+3-28
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
/*
2-
* Copyright 2012-2018 the original author or authors.
2+
* Copyright 2012-2019 the original author or authors.
33
*
44
* Licensed under the Apache License, Version 2.0 (the "License");
55
* you may not use this file except in compliance with the License.
@@ -21,15 +21,13 @@
2121
import java.util.List;
2222
import java.util.Map;
2323

24-
import org.apache.commons.logging.Log;
2524
import reactor.core.publisher.Flux;
2625
import reactor.core.publisher.Mono;
2726

2827
import org.springframework.boot.autoconfigure.web.ErrorProperties;
2928
import org.springframework.boot.autoconfigure.web.ResourceProperties;
3029
import org.springframework.boot.web.reactive.error.ErrorAttributes;
3130
import org.springframework.context.ApplicationContext;
32-
import org.springframework.http.HttpLogging;
3331
import org.springframework.http.HttpStatus;
3432
import org.springframework.http.InvalidMediaTypeException;
3533
import org.springframework.http.MediaType;
@@ -77,9 +75,6 @@ public class DefaultErrorWebExceptionHandler extends AbstractErrorWebExceptionHa
7775

7876
private static final Map<HttpStatus.Series, String> SERIES_VIEWS;
7977

80-
private static final Log logger = HttpLogging
81-
.forLogName(DefaultErrorWebExceptionHandler.class);
82-
8378
static {
8479
Map<HttpStatus.Series, String> views = new EnumMap<>(HttpStatus.Series.class);
8580
views.put(HttpStatus.Series.CLIENT_ERROR, "4xx");
@@ -128,7 +123,7 @@ protected Mono<ServerResponse> renderErrorView(ServerRequest request) {
128123
.switchIfEmpty(this.errorProperties.getWhitelabel().isEnabled()
129124
? renderDefaultErrorView(responseBody, error)
130125
: Mono.error(getError(request)))
131-
.next().doOnNext((response) -> logError(request, errorStatus));
126+
.next();
132127
}
133128

134129
/**
@@ -142,8 +137,7 @@ protected Mono<ServerResponse> renderErrorResponse(ServerRequest request) {
142137
HttpStatus errorStatus = getHttpStatus(error);
143138
return ServerResponse.status(getHttpStatus(error))
144139
.contentType(MediaType.APPLICATION_JSON_UTF8)
145-
.body(BodyInserters.fromObject(error))
146-
.doOnNext((resp) -> logError(request, errorStatus));
140+
.body(BodyInserters.fromObject(error));
147141
}
148142

149143
/**
@@ -196,23 +190,4 @@ protected RequestPredicate acceptsTextHtml() {
196190
};
197191
}
198192

199-
/**
200-
* Log the original exception if handling it results in a Server Error or a Bad
201-
* Request (Client Error with 400 status code) one.
202-
* @param request the source request
203-
* @param errorStatus the HTTP error status
204-
*/
205-
protected void logError(ServerRequest request, HttpStatus errorStatus) {
206-
Throwable ex = getError(request);
207-
if (logger.isDebugEnabled()) {
208-
logger.debug(request.exchange().getLogPrefix() + formatError(ex, request));
209-
}
210-
}
211-
212-
private String formatError(Throwable ex, ServerRequest request) {
213-
String reason = ex.getClass().getSimpleName() + ": " + ex.getMessage();
214-
return "Resolved [" + reason + "] for HTTP " + request.methodName() + " "
215-
+ request.path();
216-
}
217-
218193
}

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

+14-1
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
/*
2-
* Copyright 2012-2018 the original author or authors.
2+
* Copyright 2012-2019 the original author or authors.
33
*
44
* Licensed under the Apache License, Version 2.0 (the "License");
55
* you may not use this file except in compliance with the License.
@@ -18,6 +18,8 @@
1818

1919
import javax.validation.Valid;
2020

21+
import org.hamcrest.Matchers;
22+
import org.junit.Rule;
2123
import org.junit.Test;
2224
import reactor.core.publisher.Mono;
2325

@@ -28,6 +30,7 @@
2830
import org.springframework.boot.autoconfigure.web.reactive.ReactiveWebServerFactoryAutoConfiguration;
2931
import org.springframework.boot.autoconfigure.web.reactive.WebFluxAutoConfiguration;
3032
import org.springframework.boot.test.context.runner.ReactiveWebApplicationContextRunner;
33+
import org.springframework.boot.testsupport.rule.OutputCapture;
3134
import org.springframework.context.annotation.Configuration;
3235
import org.springframework.http.HttpStatus;
3336
import org.springframework.http.MediaType;
@@ -42,6 +45,7 @@
4245

4346
import static org.assertj.core.api.Assertions.assertThat;
4447
import static org.assertj.core.api.Assertions.assertThatExceptionOfType;
48+
import static org.hamcrest.Matchers.containsString;
4549

4650
/**
4751
* Integration tests for {@link DefaultErrorWebExceptionHandler}
@@ -50,6 +54,9 @@
5054
*/
5155
public class DefaultErrorWebExceptionHandlerIntegrationTests {
5256

57+
@Rule
58+
public OutputCapture outputCapture = new OutputCapture();
59+
5360
private ReactiveWebApplicationContextRunner contextRunner = new ReactiveWebApplicationContextRunner()
5461
.withConfiguration(AutoConfigurations.of(
5562
ReactiveWebServerFactoryAutoConfiguration.class,
@@ -73,6 +80,9 @@ public void jsonError() {
7380
.jsonPath("path").isEqualTo(("/")).jsonPath("message")
7481
.isEqualTo("Expected!").jsonPath("exception").doesNotExist()
7582
.jsonPath("trace").doesNotExist();
83+
this.outputCapture.expect(Matchers.allOf(
84+
containsString("500 Server Error for HTTP GET \"/\""),
85+
containsString("java.lang.IllegalStateException: Expected!")));
7686
});
7787
}
7888

@@ -98,6 +108,9 @@ public void htmlError() {
98108
.expectHeader().contentType(MediaType.TEXT_HTML)
99109
.expectBody(String.class).returnResult().getResponseBody();
100110
assertThat(body).contains("status: 500").contains("message: Expected!");
111+
this.outputCapture.expect(Matchers.allOf(
112+
containsString("500 Server Error for HTTP GET \"/\""),
113+
containsString("java.lang.IllegalStateException: Expected!")));
101114
});
102115
}
103116

0 commit comments

Comments
 (0)