From 80ff5ae9c513372db37eb0dbcb19048adb09b21f Mon Sep 17 00:00:00 2001 From: Violeta Georgieva Date: Tue, 13 Sep 2016 19:17:59 +0300 Subject: [PATCH] Improve exception handling when clients disconnect. Issue: SPR-14538 --- .../AbstractResponseBodyFlushProcessor.java | 4 +- .../AbstractResponseBodyProcessor.java | 4 +- .../reactive/ReactorHttpHandlerAdapter.java | 10 +++- .../reactive/RxNettyHttpHandlerAdapter.java | 11 +++- .../handler/ExceptionHandlingWebHandler.java | 60 ++++++++++++++++++- 5 files changed, 80 insertions(+), 9 deletions(-) diff --git a/spring-web/src/main/java/org/springframework/http/server/reactive/AbstractResponseBodyFlushProcessor.java b/spring-web/src/main/java/org/springframework/http/server/reactive/AbstractResponseBodyFlushProcessor.java index ef63b70377e..fdfc577ef89 100644 --- a/spring-web/src/main/java/org/springframework/http/server/reactive/AbstractResponseBodyFlushProcessor.java +++ b/spring-web/src/main/java/org/springframework/http/server/reactive/AbstractResponseBodyFlushProcessor.java @@ -74,8 +74,8 @@ abstract class AbstractResponseBodyFlushProcessor implements Processor { + LogFactory.getLog(ReactorHttpHandlerAdapter.class).error("Could not complete request", ex); + channel.status(HttpResponseStatus.INTERNAL_SERVER_ERROR); + return Mono.empty(); + }); } } diff --git a/spring-web/src/main/java/org/springframework/http/server/reactive/RxNettyHttpHandlerAdapter.java b/spring-web/src/main/java/org/springframework/http/server/reactive/RxNettyHttpHandlerAdapter.java index 6e10d15b90b..ff1792a98ce 100644 --- a/spring-web/src/main/java/org/springframework/http/server/reactive/RxNettyHttpHandlerAdapter.java +++ b/spring-web/src/main/java/org/springframework/http/server/reactive/RxNettyHttpHandlerAdapter.java @@ -17,11 +17,15 @@ package org.springframework.http.server.reactive; import io.netty.buffer.ByteBuf; +import io.netty.handler.codec.http.HttpResponseStatus; import io.reactivex.netty.protocol.http.server.HttpServerRequest; import io.reactivex.netty.protocol.http.server.HttpServerResponse; import io.reactivex.netty.protocol.http.server.RequestHandler; + +import org.apache.commons.logging.LogFactory; import org.reactivestreams.Publisher; import reactor.adapter.RxJava1Adapter; +import reactor.core.publisher.Mono; import rx.Observable; import org.springframework.core.io.buffer.NettyDataBufferFactory; @@ -49,7 +53,12 @@ public class RxNettyHttpHandlerAdapter implements RequestHandler result = this.httpHandler.handle(adaptedRequest, adaptedResponse); + Publisher result = this.httpHandler.handle(adaptedRequest, adaptedResponse) + .otherwise(ex -> { + LogFactory.getLog(RxNettyHttpHandlerAdapter.class).error("Could not complete request", ex); + response.setStatus(HttpResponseStatus.INTERNAL_SERVER_ERROR); + return Mono.empty(); + }); return RxJava1Adapter.publisherToObservable(result); } diff --git a/spring-web/src/main/java/org/springframework/web/server/handler/ExceptionHandlingWebHandler.java b/spring-web/src/main/java/org/springframework/web/server/handler/ExceptionHandlingWebHandler.java index 273abb4fec6..f268d442b40 100644 --- a/spring-web/src/main/java/org/springframework/web/server/handler/ExceptionHandlingWebHandler.java +++ b/spring-web/src/main/java/org/springframework/web/server/handler/ExceptionHandlingWebHandler.java @@ -18,12 +18,15 @@ package org.springframework.web.server.handler; import java.util.Arrays; import java.util.Collections; +import java.util.HashSet; import java.util.List; +import java.util.Set; import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; import reactor.core.publisher.Mono; +import org.springframework.core.NestedCheckedException; import org.springframework.http.HttpStatus; import org.springframework.web.server.ServerWebExchange; import org.springframework.web.server.WebExceptionHandler; @@ -37,6 +40,36 @@ import org.springframework.web.server.WebHandler; * @since 5.0 */ public class ExceptionHandlingWebHandler extends WebHandlerDecorator { + /** + * Log category to use on network IO exceptions after a client has gone away. + *

The Servlet API does not provide notifications when a client disconnects; + * see SERVLET_SPEC-44. + * Therefore network IO failures may occur simply because a client has gone away, + * and that can fill the logs with unnecessary stack traces. + *

We make a best effort to identify such network failures, on a per-server + * basis, and log them under a separate log category. A simple one-line message + * is logged at DEBUG level, while a full stack trace is shown at TRACE level. + * @see #disconnectedClientLogger + */ + private static final String DISCONNECTED_CLIENT_LOG_CATEGORY = + "org.springframework.web.server.handler.DisconnectedClient"; + + /** + * Separate logger to use on network IO failure after a client has gone away. + * @see #DISCONNECTED_CLIENT_LOG_CATEGORY + */ + private static final Log disconnectedClientLogger = LogFactory.getLog(DISCONNECTED_CLIENT_LOG_CATEGORY); + + private static final Set disconnectedClientExceptions; + + static { + Set set = new HashSet<>(3); + set.add("ClientAbortException"); // Tomcat + set.add("EOFException"); // Tomcat + set.add("EofException"); // Jetty + // java.io.IOException "Broken pipe" on WildFly, Glassfish (already covered) + disconnectedClientExceptions = Collections.unmodifiableSet(set); + } private static Log logger = LogFactory.getLog(ExceptionHandlingWebHandler.class); @@ -77,11 +110,32 @@ public class ExceptionHandlingWebHandler extends WebHandlerDecorator { } private Mono handleUnresolvedException(ServerWebExchange exchange, Throwable ex) { - if (logger.isDebugEnabled()) { - logger.debug("Could not complete request", ex); - } + logError(ex); exchange.getResponse().setStatusCode(HttpStatus.INTERNAL_SERVER_ERROR); return Mono.empty(); } + private void logError(Throwable t) { + @SuppressWarnings("serial") + NestedCheckedException nestedException = new NestedCheckedException("", t) {}; + + if ("Broken pipe".equalsIgnoreCase(nestedException.getMostSpecificCause().getMessage()) || + disconnectedClientExceptions.contains(t.getClass().getSimpleName())) { + + if (disconnectedClientLogger.isTraceEnabled()) { + disconnectedClientLogger.trace("Looks like the client has gone away", t); + } + else if (disconnectedClientLogger.isDebugEnabled()) { + disconnectedClientLogger.debug("Looks like the client has gone away: " + + nestedException.getMessage() + " (For full stack trace, set the '" + + DISCONNECTED_CLIENT_LOG_CATEGORY + "' log category to TRACE level)"); + } + } + else { + if (logger.isDebugEnabled()) { + logger.debug("Could not complete request", t); + } + } + } + }