From fd90b73748112122c57b0346d48d08e3574accd7 Mon Sep 17 00:00:00 2001 From: Rossen Stoyanchev Date: Tue, 3 Jul 2018 15:54:19 -0400 Subject: [PATCH] Correlated WebFlux server log messages Issue: SPR-16966 --- .../reactive/server/MockServerSpecTests.java | 17 +++++++-- .../web/server/ServerWebExchange.java | 20 ++++++++++ .../server/ServerWebExchangeDecorator.java | 5 +++ .../adapter/DefaultServerWebExchange.java | 15 ++++++++ .../server/adapter/HttpWebHandlerAdapter.java | 37 ++++++++++++------- .../ResponseStatusExceptionHandler.java | 5 ++- .../server/DefaultServerRequestBuilder.java | 5 +++ .../function/server/RouterFunctions.java | 6 ++- .../handler/AbstractHandlerMapping.java | 2 +- .../handler/AbstractUrlHandlerMapping.java | 2 +- .../resource/AppCacheManifestTransformer.java | 3 +- .../resource/CachingResourceResolver.java | 3 +- .../resource/CachingResourceTransformer.java | 2 +- .../resource/EncodedResourceResolver.java | 3 +- .../resource/GzipResourceResolver.java | 3 +- .../resource/ResourceUrlProvider.java | 6 +-- .../reactive/resource/ResourceWebHandler.java | 8 +++- .../resource/VersionResourceResolver.java | 5 ++- .../result/HandlerResultHandlerSupport.java | 9 +++-- .../method/AbstractHandlerMethodMapping.java | 2 +- .../result/method/InvocableHandlerMethod.java | 14 ++++--- ...AbstractMessageReaderArgumentResolver.java | 10 +++-- .../AbstractMessageWriterResultHandler.java | 6 ++- .../RequestMappingHandlerAdapter.java | 4 +- .../reactive/result/view/AbstractView.java | 2 +- .../view/freemarker/FreeMarkerView.java | 2 +- .../support/HandshakeWebSocketService.java | 10 ++--- 27 files changed, 146 insertions(+), 60 deletions(-) diff --git a/spring-test/src/test/java/org/springframework/test/web/reactive/server/MockServerSpecTests.java b/spring-test/src/test/java/org/springframework/test/web/reactive/server/MockServerSpecTests.java index 227166e8fd0..9e14f99d4df 100644 --- a/spring-test/src/test/java/org/springframework/test/web/reactive/server/MockServerSpecTests.java +++ b/spring-test/src/test/java/org/springframework/test/web/reactive/server/MockServerSpecTests.java @@ -27,6 +27,9 @@ import org.springframework.web.server.WebFilter; import org.springframework.web.server.WebFilterChain; import org.springframework.web.server.adapter.WebHttpHandlerBuilder; +import static org.hamcrest.MatcherAssert.*; +import static org.hamcrest.core.StringContains.*; + /** * Unit tests for {@link AbstractMockServerSpec}. * @author Rossen Stoyanchev @@ -49,8 +52,11 @@ public class MockServerSpecTests { } }); - this.serverSpec.build().get().uri("/").exchange().expectBody(String.class) - .isEqualTo("{test-attribute=:A:B}"); + this.serverSpec.build().get().uri("/") + .exchange() + .expectBody(String.class) + .consumeWith(result -> assertThat( + result.getResponseBody(), containsString("test-attribute=:A:B"))); } @Test @@ -70,8 +76,11 @@ public class MockServerSpecTests { } }); - this.serverSpec.build().get().uri("/").exchange().expectBody(String.class) - .isEqualTo("{test-attribute=:Fwk-A:Fwk-B:App-A:App-B}"); + this.serverSpec.build().get().uri("/") + .exchange() + .expectBody(String.class) + .consumeWith(result -> assertThat( + result.getResponseBody(), containsString("test-attribute=:Fwk-A:Fwk-B:App-A:App-B"))); } diff --git a/spring-web/src/main/java/org/springframework/web/server/ServerWebExchange.java b/spring-web/src/main/java/org/springframework/web/server/ServerWebExchange.java index 905e21d3784..46dd658db31 100644 --- a/spring-web/src/main/java/org/springframework/web/server/ServerWebExchange.java +++ b/spring-web/src/main/java/org/springframework/web/server/ServerWebExchange.java @@ -43,6 +43,16 @@ import org.springframework.util.MultiValueMap; */ public interface ServerWebExchange { + /** + * Name of {@link #getAttributes() attribute} whose value correlates log + * messages for the exchange. Use {@link #getLogPrefix()} to obtain a + * consistently formatted prefix based on this attribute. + * @since 5.1 + * @see #getLogPrefix() + */ + String LOG_ID_ATTRIBUTE = ServerWebExchange.class.getName() + ".LOG_ID"; + + /** * Return the current HTTP request. */ @@ -208,6 +218,16 @@ public interface ServerWebExchange { */ void addUrlTransformer(Function transformer); + /** + * Return a common prefix to use for log messages related to the exchange. + * The prefix is based on the value of the {@link #LOG_ID_ATTRIBUTE} + * attribute along with some extra formatting. + * @return the log message prefix or an empty String if the + * {@link #LOG_ID_ATTRIBUTE} is not set. + * @since 5.1 + */ + String getLogPrefix(); + /** * Return a builder to mutate properties of this exchange by wrapping it * with {@link ServerWebExchangeDecorator} and returning either mutated diff --git a/spring-web/src/main/java/org/springframework/web/server/ServerWebExchangeDecorator.java b/spring-web/src/main/java/org/springframework/web/server/ServerWebExchangeDecorator.java index 32c61c88419..68052aa6e6c 100644 --- a/spring-web/src/main/java/org/springframework/web/server/ServerWebExchangeDecorator.java +++ b/spring-web/src/main/java/org/springframework/web/server/ServerWebExchangeDecorator.java @@ -137,6 +137,11 @@ public class ServerWebExchangeDecorator implements ServerWebExchange { getDelegate().addUrlTransformer(transformer); } + @Override + public String getLogPrefix() { + return getDelegate().getLogPrefix(); + } + @Override public String toString() { return getClass().getSimpleName() + " [delegate=" + getDelegate() + "]"; diff --git a/spring-web/src/main/java/org/springframework/web/server/adapter/DefaultServerWebExchange.java b/spring-web/src/main/java/org/springframework/web/server/adapter/DefaultServerWebExchange.java index c4a136ed289..5bc0068794e 100644 --- a/spring-web/src/main/java/org/springframework/web/server/adapter/DefaultServerWebExchange.java +++ b/spring-web/src/main/java/org/springframework/web/server/adapter/DefaultServerWebExchange.java @@ -98,6 +98,11 @@ public class DefaultServerWebExchange implements ServerWebExchange { private Function urlTransformer = url -> url; + @Nullable + private Object logId; + + private String logPrefix = ""; + public DefaultServerWebExchange(ServerHttpRequest request, ServerHttpResponse response, WebSessionManager sessionManager, ServerCodecConfigurer codecConfigurer, @@ -355,4 +360,14 @@ public class DefaultServerWebExchange implements ServerWebExchange { this.urlTransformer = this.urlTransformer.andThen(transformer); } + @Override + public String getLogPrefix() { + Object value = getAttribute(LOG_ID_ATTRIBUTE); + if (this.logId != value) { + this.logId = value; + this.logPrefix = value != null ? "[" + value + "] " : ""; + } + return this.logPrefix; + } + } diff --git a/spring-web/src/main/java/org/springframework/web/server/adapter/HttpWebHandlerAdapter.java b/spring-web/src/main/java/org/springframework/web/server/adapter/HttpWebHandlerAdapter.java index 462959983db..6ba86ad1107 100644 --- a/spring-web/src/main/java/org/springframework/web/server/adapter/HttpWebHandlerAdapter.java +++ b/spring-web/src/main/java/org/springframework/web/server/adapter/HttpWebHandlerAdapter.java @@ -34,6 +34,7 @@ import org.springframework.http.server.reactive.ServerHttpRequest; import org.springframework.http.server.reactive.ServerHttpResponse; import org.springframework.lang.Nullable; import org.springframework.util.Assert; +import org.springframework.util.ObjectUtils; import org.springframework.util.StringUtils; import org.springframework.web.server.ServerWebExchange; import org.springframework.web.server.WebHandler; @@ -214,11 +215,15 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa public Mono handle(ServerHttpRequest request, ServerHttpResponse response) { ServerWebExchange exchange = createExchange(request, response); + + String logId = ObjectUtils.getIdentityHexString(request); + exchange.getAttributes().put(ServerWebExchange.LOG_ID_ATTRIBUTE, logId); + logExchange(exchange); return getDelegate().handle(exchange) - .doOnSuccess(aVoid -> logResponse(response)) - .onErrorResume(ex -> handleUnresolvedError(request, response, ex)) + .doOnSuccess(aVoid -> logResponse(exchange)) + .onErrorResume(ex -> handleUnresolvedError(exchange, ex)) .then(Mono.defer(response::setComplete)); } @@ -229,13 +234,14 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa private void logExchange(ServerWebExchange exchange) { if (logger.isDebugEnabled()) { + String logPrefix = exchange.getLogPrefix(); ServerHttpRequest request = exchange.getRequest(); if (logger.isTraceEnabled()) { String headers = this.disableLoggingRequestDetails ? "" : ", headers=" + request.getHeaders(); - logger.trace(formatRequest(request) + headers); + logger.trace(logPrefix + formatRequest(request) + headers); } else { - logger.debug(formatRequest(request)); + logger.debug(logPrefix + formatRequest(request)); } } } @@ -249,40 +255,45 @@ public class HttpWebHandlerAdapter extends WebHandlerDecorator implements HttpHa return "HTTP " + request.getMethod() + " \"" + request.getPath() + query + "\""; } - private void logResponse(ServerHttpResponse response) { + private void logResponse(ServerWebExchange exchange) { if (logger.isDebugEnabled()) { + String logPrefix = exchange.getLogPrefix(); + ServerHttpResponse response = exchange.getResponse(); HttpStatus status = response.getStatusCode(); String message = "Completed " + (status != null ? status : "200 OK"); - if (logger.isTraceEnabled()) { String headers = this.disableLoggingRequestDetails ? "" : ", headers=" + response.getHeaders(); - logger.trace(message + headers); + logger.trace(logPrefix + message + headers); } else { - logger.debug(message); + logger.debug(logPrefix + message); } } } - private Mono handleUnresolvedError(ServerHttpRequest request, ServerHttpResponse response, Throwable ex) { + private Mono handleUnresolvedError(ServerWebExchange exchange, Throwable ex) { + + ServerHttpRequest request = exchange.getRequest(); + ServerHttpResponse response = exchange.getResponse(); + String logPrefix = exchange.getLogPrefix(); if (isDisconnectedClientError(ex)) { if (lostClientLogger.isTraceEnabled()) { - lostClientLogger.trace("Client went away", ex); + lostClientLogger.trace(logPrefix + "Client went away", ex); } else if (lostClientLogger.isDebugEnabled()) { - lostClientLogger.debug("Client went away: " + ex + + lostClientLogger.debug(logPrefix + "Client went away: " + ex + " (stacktrace at TRACE level for '" + DISCONNECTED_CLIENT_LOG_CATEGORY + "')"); } return Mono.empty(); } else if (response.setStatusCode(HttpStatus.INTERNAL_SERVER_ERROR)) { - logger.error("500 Server Error for " + formatRequest(request), ex); + logger.error(logPrefix + "500 Server Error for " + formatRequest(request), ex); return Mono.empty(); } else { // After the response is committed, propagate errors to the server.. - logger.error("Error [" + ex + "] for " + formatRequest(request) + + logger.error(logPrefix + "Error [" + ex + "] for " + formatRequest(request) + ", but ServerHttpResponse already committed (" + response.getStatusCode() + ")"); return Mono.error(ex); } diff --git a/spring-web/src/main/java/org/springframework/web/server/handler/ResponseStatusExceptionHandler.java b/spring-web/src/main/java/org/springframework/web/server/handler/ResponseStatusExceptionHandler.java index 101decfde79..c7ed4b31103 100644 --- a/spring-web/src/main/java/org/springframework/web/server/handler/ResponseStatusExceptionHandler.java +++ b/spring-web/src/main/java/org/springframework/web/server/handler/ResponseStatusExceptionHandler.java @@ -70,11 +70,12 @@ public class ResponseStatusExceptionHandler implements WebExceptionHandler { // Mirrors AbstractHandlerExceptionResolver in spring-webmvc.. + String logPrefix = exchange.getLogPrefix(); if (this.warnLogger != null && this.warnLogger.isWarnEnabled()) { - this.warnLogger.warn(formatError(ex, exchange.getRequest()), ex); + this.warnLogger.warn(logPrefix + formatError(ex, exchange.getRequest()), ex); } else if (logger.isDebugEnabled()) { - logger.debug(formatError(ex, exchange.getRequest())); + logger.debug(logPrefix + formatError(ex, exchange.getRequest())); } return exchange.getResponse().setComplete(); diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/function/server/DefaultServerRequestBuilder.java b/spring-webflux/src/main/java/org/springframework/web/reactive/function/server/DefaultServerRequestBuilder.java index 4a15d0f3988..f850c052b52 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/function/server/DefaultServerRequestBuilder.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/function/server/DefaultServerRequestBuilder.java @@ -429,5 +429,10 @@ class DefaultServerRequestBuilder implements ServerRequest.Builder { public void addUrlTransformer(Function transformer) { this.delegate.addUrlTransformer(transformer); } + + @Override + public String getLogPrefix() { + return this.delegate.getLogPrefix(); + } } } diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/function/server/RouterFunctions.java b/spring-webflux/src/main/java/org/springframework/web/reactive/function/server/RouterFunctions.java index 2c5d94f7f8b..cc7d2039e15 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/function/server/RouterFunctions.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/function/server/RouterFunctions.java @@ -809,7 +809,8 @@ public abstract class RouterFunctions { public Mono> route(ServerRequest request) { if (this.predicate.test(request)) { if (logger.isTraceEnabled()) { - logger.trace(String.format("Matched %s", this.predicate)); + String logPrefix = request.exchange().getLogPrefix(); + logger.trace(logPrefix + String.format("Matched %s", this.predicate)); } return Mono.just(this.handlerFunction); } @@ -844,7 +845,8 @@ public abstract class RouterFunctions { return this.predicate.nest(serverRequest) .map(nestedRequest -> { if (logger.isTraceEnabled()) { - logger.trace(String.format("Matched nested %s", this.predicate)); + String logPrefix = serverRequest.exchange().getLogPrefix(); + logger.trace(logPrefix + String.format("Matched nested %s", this.predicate)); } return this.routerFunction.route(nestedRequest) .doOnNext(match -> { diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/handler/AbstractHandlerMapping.java b/spring-webflux/src/main/java/org/springframework/web/reactive/handler/AbstractHandlerMapping.java index 73306ce0c06..c877a8b9358 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/handler/AbstractHandlerMapping.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/handler/AbstractHandlerMapping.java @@ -160,7 +160,7 @@ public abstract class AbstractHandlerMapping extends ApplicationObjectSupport public Mono getHandler(ServerWebExchange exchange) { return getHandlerInternal(exchange).map(handler -> { if (logger.isDebugEnabled()) { - logger.debug("Mapped to " + handler); + logger.debug(exchange.getLogPrefix() + "Mapped to " + handler); } if (CorsUtils.isCorsRequest(exchange.getRequest())) { CorsConfiguration configA = this.globalCorsConfigSource.getCorsConfiguration(exchange); diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/handler/AbstractUrlHandlerMapping.java b/spring-webflux/src/main/java/org/springframework/web/reactive/handler/AbstractUrlHandlerMapping.java index 2922a9d4b92..a5de358fd19 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/handler/AbstractUrlHandlerMapping.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/handler/AbstractUrlHandlerMapping.java @@ -119,7 +119,7 @@ public abstract class AbstractUrlHandlerMapping extends AbstractHandlerMapping { if (matches.size() > 1) { matches.sort(PathPattern.SPECIFICITY_COMPARATOR); if (logger.isTraceEnabled()) { - logger.debug("Matching patterns " + matches); + logger.debug(exchange.getLogPrefix() + "Matching patterns " + matches); } } diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/AppCacheManifestTransformer.java b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/AppCacheManifestTransformer.java index c8564e8c843..bca10811db3 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/AppCacheManifestTransformer.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/AppCacheManifestTransformer.java @@ -127,7 +127,8 @@ public class AppCacheManifestTransformer extends ResourceTransformerSupport { if (!content.startsWith(MANIFEST_HEADER)) { if (logger.isTraceEnabled()) { - logger.trace("Skipping " + resource + ": Manifest does not start with 'CACHE MANIFEST'"); + logger.trace(exchange.getLogPrefix() + + "Skipping " + resource + ": Manifest does not start with 'CACHE MANIFEST'"); } return Mono.just(resource); } diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/CachingResourceResolver.java b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/CachingResourceResolver.java index 31a7bdb2a70..8e105c997e5 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/CachingResourceResolver.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/CachingResourceResolver.java @@ -112,7 +112,8 @@ public class CachingResourceResolver extends AbstractResourceResolver { Resource cachedResource = this.cache.get(key, Resource.class); if (cachedResource != null) { - logger.trace("Resource resolved from cache"); + String logPrefix = exchange != null ? exchange.getLogPrefix() : ""; + logger.trace(logPrefix + "Resource resolved from cache"); return Mono.just(cachedResource); } diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/CachingResourceTransformer.java b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/CachingResourceTransformer.java index 37457096a4d..589bf155c0f 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/CachingResourceTransformer.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/CachingResourceTransformer.java @@ -69,7 +69,7 @@ public class CachingResourceTransformer implements ResourceTransformer { Resource cachedResource = this.cache.get(resource, Resource.class); if (cachedResource != null) { - logger.trace("Resource resolved from cache"); + logger.trace(exchange.getLogPrefix() + "Resource resolved from cache"); return Mono.just(cachedResource); } diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/EncodedResourceResolver.java b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/EncodedResourceResolver.java index 6bcc8822a35..479e106277d 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/EncodedResourceResolver.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/EncodedResourceResolver.java @@ -153,7 +153,8 @@ public class EncodedResourceResolver extends AbstractResourceResolver { } } catch (IOException ex) { - logger.trace("No " + coding + " resource for [" + resource.getFilename() + "]", ex); + logger.trace(exchange.getLogPrefix() + + "No " + coding + " resource for [" + resource.getFilename() + "]", ex); } } } diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/GzipResourceResolver.java b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/GzipResourceResolver.java index 13793891186..5b43aec5712 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/GzipResourceResolver.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/GzipResourceResolver.java @@ -59,7 +59,8 @@ public class GzipResourceResolver extends AbstractResourceResolver { } } catch (IOException ex) { - logger.trace("No gzip resource for [" + resource.getFilename() + "]", ex); + String logPrefix = exchange != null ? exchange.getLogPrefix() : ""; + logger.trace(logPrefix + "No gzip resource for [" + resource.getFilename() + "]", ex); } } return resource; diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/ResourceUrlProvider.java b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/ResourceUrlProvider.java index 32fabca0889..04a97582e2e 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/ResourceUrlProvider.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/ResourceUrlProvider.java @@ -124,7 +124,7 @@ public class ResourceUrlProvider implements ApplicationListener + return resolveResourceUrl(exchange, parsedLookupPath).map(resolvedPath -> request.getPath().contextPath().value() + resolvedPath + query); } @@ -141,7 +141,7 @@ public class ResourceUrlProvider implements ApplicationListener resolveResourceUrl(PathContainer lookupPath) { + private Mono resolveResourceUrl(ServerWebExchange exchange, PathContainer lookupPath) { return this.handlerMap.entrySet().stream() .filter(entry -> entry.getKey().matches(lookupPath)) .sorted((entry1, entry2) -> @@ -159,7 +159,7 @@ public class ResourceUrlProvider implements ApplicationListener{ if (logger.isTraceEnabled()) { - logger.trace("No match for \"" + lookupPath + "\""); + logger.trace(exchange.getLogPrefix() + "No match for \"" + lookupPath + "\""); } return Mono.empty(); }); diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/ResourceWebHandler.java b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/ResourceWebHandler.java index ec5379bfa62..cc6681a46d1 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/ResourceWebHandler.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/ResourceWebHandler.java @@ -23,8 +23,11 @@ import java.time.Instant; import java.util.ArrayList; import java.util.Collections; import java.util.EnumSet; +import java.util.HashMap; import java.util.List; +import java.util.Map; import java.util.Set; +import java.util.function.Supplier; import java.util.stream.Collectors; import org.apache.commons.logging.Log; @@ -33,6 +36,7 @@ import reactor.core.publisher.Mono; import org.springframework.beans.factory.InitializingBean; import org.springframework.core.ResolvableType; +import org.springframework.core.codec.Encoder; import org.springframework.core.io.Resource; import org.springframework.core.io.ResourceLoader; import org.springframework.http.CacheControl; @@ -322,7 +326,7 @@ public class ResourceWebHandler implements WebHandler, InitializingBean { public Mono handle(ServerWebExchange exchange) { return getResource(exchange) .switchIfEmpty(Mono.defer(() -> { - logger.debug("Resource not found"); + logger.debug(exchange.getLogPrefix() + "Resource not found"); return Mono.error(NOT_FOUND_EXCEPTION); })) .flatMap(resource -> { @@ -341,7 +345,7 @@ public class ResourceWebHandler implements WebHandler, InitializingBean { // Header phase if (exchange.checkNotModified(Instant.ofEpochMilli(resource.lastModified()))) { - logger.trace("Resource not modified"); + logger.trace(exchange.getLogPrefix() + "Resource not modified"); return Mono.empty(); } diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/VersionResourceResolver.java b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/VersionResourceResolver.java index 1639f97c809..15014c962c0 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/resource/VersionResourceResolver.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/resource/VersionResourceResolver.java @@ -185,8 +185,9 @@ public class VersionResourceResolver extends AbstractResourceResolver { } else { if (logger.isTraceEnabled()) { - logger.trace("Found resource for \"" + requestPath + "\", but version [" + - candidate + "] does not match"); + String logPrefix = exchange != null ? exchange.getLogPrefix() : ""; + logger.trace(logPrefix + "Found resource for \"" + requestPath + + "\", but version [" + candidate + "] does not match"); } return false; } diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/result/HandlerResultHandlerSupport.java b/spring-webflux/src/main/java/org/springframework/web/reactive/result/HandlerResultHandlerSupport.java index b2d9288d2aa..c91c56a97cc 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/result/HandlerResultHandlerSupport.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/result/HandlerResultHandlerSupport.java @@ -123,7 +123,7 @@ public abstract class HandlerResultHandlerSupport implements Ordered { MediaType contentType = exchange.getResponse().getHeaders().getContentType(); if (contentType != null && contentType.isConcrete()) { if (logger.isDebugEnabled()) { - logger.debug("Found 'Content-Type:" + contentType + "' in response"); + logger.debug(exchange.getLogPrefix() + "Found 'Content-Type:" + contentType + "' in response"); } return contentType; } @@ -146,21 +146,22 @@ public abstract class HandlerResultHandlerSupport implements Ordered { for (MediaType mediaType : result) { if (mediaType.isConcrete()) { if (logger.isDebugEnabled()) { - logger.debug("Using '" + mediaType + "' given " + acceptableTypes); + logger.debug(exchange.getLogPrefix() + "Using '" + mediaType + "' given " + acceptableTypes); } return mediaType; } else if (mediaType.equals(MediaType.ALL) || mediaType.equals(MEDIA_TYPE_APPLICATION_ALL)) { mediaType = MediaType.APPLICATION_OCTET_STREAM; if (logger.isDebugEnabled()) { - logger.debug("Using '" + mediaType + "' given " + acceptableTypes); + logger.debug(exchange.getLogPrefix() + "Using '" + mediaType + "' given " + acceptableTypes); } return mediaType; } } if (logger.isDebugEnabled()) { - logger.debug("No match for " + acceptableTypes + ", supported: " + producibleTypes); + logger.debug(exchange.getLogPrefix() + + "No match for " + acceptableTypes + ", supported: " + producibleTypes); } return null; diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/AbstractHandlerMethodMapping.java b/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/AbstractHandlerMethodMapping.java index 6d060c4da6c..68d008e76af 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/AbstractHandlerMethodMapping.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/AbstractHandlerMethodMapping.java @@ -305,7 +305,7 @@ public abstract class AbstractHandlerMethodMapping extends AbstractHandlerMap Match bestMatch = matches.get(0); if (matches.size() > 1) { if (logger.isTraceEnabled()) { - logger.trace(matches.size() + " matching mappings: " + matches); + logger.trace(exchange.getLogPrefix() + matches.size() + " matching mappings: " + matches); } if (CorsUtils.isPreFlightRequest(exchange.getRequest())) { return PREFLIGHT_AMBIGUOUS_MATCH; diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/InvocableHandlerMethod.java b/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/InvocableHandlerMethod.java index a6c22f1164f..644fb93fc19 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/InvocableHandlerMethod.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/InvocableHandlerMethod.java @@ -182,7 +182,7 @@ public class InvocableHandlerMethod extends HandlerMethod { return findProvidedArgument(param, providedArgs) .map(Mono::just) .orElseGet(() -> { - HandlerMethodArgumentResolver resolver = findResolver(param); + HandlerMethodArgumentResolver resolver = findResolver(exchange, param); return resolveArg(resolver, param, bindingContext, exchange); }); @@ -207,7 +207,7 @@ public class InvocableHandlerMethod extends HandlerMethod { .findFirst(); } - private HandlerMethodArgumentResolver findResolver(MethodParameter param) { + private HandlerMethodArgumentResolver findResolver(ServerWebExchange exchange, MethodParameter param) { return this.resolvers.stream() .filter(r -> r.supportsParameter(param)) .findFirst().orElseThrow(() -> @@ -220,20 +220,22 @@ public class InvocableHandlerMethod extends HandlerMethod { try { return resolver.resolveArgument(parameter, bindingContext, exchange) .defaultIfEmpty(NO_ARG_VALUE) - .doOnError(cause -> logArgumentErrorIfNecessary(parameter, cause)); + .doOnError(cause -> logArgumentErrorIfNecessary(exchange, parameter, cause)); } catch (Exception ex) { - logArgumentErrorIfNecessary(parameter, ex); + logArgumentErrorIfNecessary(exchange, parameter, ex); return Mono.error(ex); } } - private void logArgumentErrorIfNecessary(MethodParameter parameter, Throwable cause) { + private void logArgumentErrorIfNecessary( + ServerWebExchange exchange, MethodParameter parameter, Throwable cause) { + // Leave stack trace for later, if error is not handled.. String message = cause.getMessage(); if (!message.contains(parameter.getExecutable().toGenericString())) { if (logger.isDebugEnabled()) { - logger.debug(formatArgumentError(parameter, message)); + logger.debug(exchange.getLogPrefix() + formatArgumentError(parameter, message)); } } } diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/annotation/AbstractMessageReaderArgumentResolver.java b/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/annotation/AbstractMessageReaderArgumentResolver.java index 447ec388d23..9af6b53c96f 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/annotation/AbstractMessageReaderArgumentResolver.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/annotation/AbstractMessageReaderArgumentResolver.java @@ -34,6 +34,7 @@ import org.springframework.core.ReactiveAdapterRegistry; import org.springframework.core.ResolvableType; import org.springframework.core.annotation.AnnotationUtils; import org.springframework.core.codec.DecodingException; +import org.springframework.core.codec.Encoder; import org.springframework.core.io.buffer.DataBuffer; import org.springframework.http.HttpMethod; import org.springframework.http.MediaType; @@ -153,8 +154,9 @@ public abstract class AbstractMessageReaderArgumentResolver extends HandlerMetho MediaType mediaType = (contentType != null ? contentType : MediaType.APPLICATION_OCTET_STREAM); if (logger.isDebugEnabled()) { - logger.debug(contentType != null ? "Content-Type:" + contentType : - "No Content-Type, using " + MediaType.APPLICATION_OCTET_STREAM); + logger.debug(exchange.getLogPrefix() + (contentType != null ? + "Content-Type:" + contentType : + "No Content-Type, using " + MediaType.APPLICATION_OCTET_STREAM)); } for (HttpMessageReader reader : getMessageReaders()) { @@ -162,7 +164,7 @@ public abstract class AbstractMessageReaderArgumentResolver extends HandlerMetho Map readHints = Collections.emptyMap(); if (adapter != null && adapter.isMultiValue()) { if (logger.isDebugEnabled()) { - logger.debug("0..N [" + elementType + "]"); + logger.debug(exchange.getLogPrefix() + "0..N [" + elementType + "]"); } Flux flux = reader.read(actualType, elementType, request, response, readHints); flux = flux.onErrorResume(ex -> Flux.error(handleReadError(bodyParam, ex))); @@ -179,7 +181,7 @@ public abstract class AbstractMessageReaderArgumentResolver extends HandlerMetho else { // Single-value (with or without reactive type wrapper) if (logger.isDebugEnabled()) { - logger.debug("0..1 [" + elementType + "]"); + logger.debug(exchange.getLogPrefix() + "0..1 [" + elementType + "]"); } Mono mono = reader.readMono(actualType, elementType, request, response, readHints); mono = mono.onErrorResume(ex -> Mono.error(handleReadError(bodyParam, ex))); diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/annotation/AbstractMessageWriterResultHandler.java b/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/annotation/AbstractMessageWriterResultHandler.java index 32ad6b08bfe..63cb056101f 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/annotation/AbstractMessageWriterResultHandler.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/annotation/AbstractMessageWriterResultHandler.java @@ -18,6 +18,7 @@ package org.springframework.web.reactive.result.method.annotation; import java.util.Collections; import java.util.List; +import java.util.Map; import java.util.stream.Collectors; import org.reactivestreams.Publisher; @@ -27,6 +28,7 @@ import org.springframework.core.MethodParameter; import org.springframework.core.ReactiveAdapter; import org.springframework.core.ReactiveAdapterRegistry; import org.springframework.core.ResolvableType; +import org.springframework.core.codec.Encoder; import org.springframework.http.MediaType; import org.springframework.http.codec.HttpMessageWriter; import org.springframework.http.server.reactive.ServerHttpRequest; @@ -140,8 +142,10 @@ public abstract class AbstractMessageWriterResultHandler extends HandlerResultHa ServerHttpResponse response = exchange.getResponse(); MediaType bestMediaType = selectMediaType(exchange, () -> getMediaTypesFor(elementType)); if (bestMediaType != null) { + String logPrefix = exchange.getLogPrefix(); if (logger.isDebugEnabled()) { - logger.debug((publisher instanceof Mono ? "0..1" : "0..N") + " [" + elementType + "]"); + logger.debug(logPrefix + + (publisher instanceof Mono ? "0..1" : "0..N") + " [" + elementType + "]"); } for (HttpMessageWriter writer : getMessageWriters()) { if (writer.canWrite(elementType, bestMediaType)) { diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/annotation/RequestMappingHandlerAdapter.java b/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/annotation/RequestMappingHandlerAdapter.java index 6a1c5f70001..0f8f787a011 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/annotation/RequestMappingHandlerAdapter.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/result/method/annotation/RequestMappingHandlerAdapter.java @@ -214,7 +214,7 @@ public class RequestMappingHandlerAdapter implements HandlerAdapter, Application if (invocable != null) { try { if (logger.isDebugEnabled()) { - logger.debug("Using @ExceptionHandler " + invocable); + logger.debug(exchange.getLogPrefix() + "Using @ExceptionHandler " + invocable); } bindingContext.getModel().asMap().clear(); Throwable cause = exception.getCause(); @@ -227,7 +227,7 @@ public class RequestMappingHandlerAdapter implements HandlerAdapter, Application } catch (Throwable invocationEx) { if (logger.isWarnEnabled()) { - logger.warn("Failure in @ExceptionHandler " + invocable, invocationEx); + logger.warn(exchange.getLogPrefix() + "Failure in @ExceptionHandler " + invocable, invocationEx); } } } diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/result/view/AbstractView.java b/spring-webflux/src/main/java/org/springframework/web/reactive/result/view/AbstractView.java index 3b3efd5e4c1..2f311857447 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/result/view/AbstractView.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/result/view/AbstractView.java @@ -189,7 +189,7 @@ public abstract class AbstractView implements View, BeanNameAware, ApplicationCo ServerWebExchange exchange) { if (logger.isDebugEnabled()) { - logger.debug("View " + formatViewName() + + logger.debug(exchange.getLogPrefix() + "View " + formatViewName() + ", model " + (model != null ? model : Collections.emptyMap())); } diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/result/view/freemarker/FreeMarkerView.java b/spring-webflux/src/main/java/org/springframework/web/reactive/result/view/freemarker/FreeMarkerView.java index 88e51884756..d9f998bd100 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/result/view/freemarker/FreeMarkerView.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/result/view/freemarker/FreeMarkerView.java @@ -188,7 +188,7 @@ public class FreeMarkerView extends AbstractUrlBasedView { SimpleHash freeMarkerModel = getTemplateModel(renderAttributes, exchange); if (logger.isDebugEnabled()) { - logger.debug("Rendering [" + getUrl() + "]"); + logger.debug(exchange.getLogPrefix() + "Rendering [" + getUrl() + "]"); } Locale locale = LocaleContextHolder.getLocale(exchange.getLocaleContext()); diff --git a/spring-webflux/src/main/java/org/springframework/web/reactive/socket/server/support/HandshakeWebSocketService.java b/spring-webflux/src/main/java/org/springframework/web/reactive/socket/server/support/HandshakeWebSocketService.java index 4e712bf5d04..354536e2375 100644 --- a/spring-webflux/src/main/java/org/springframework/web/reactive/socket/server/support/HandshakeWebSocketService.java +++ b/spring-webflux/src/main/java/org/springframework/web/reactive/socket/server/support/HandshakeWebSocketService.java @@ -214,17 +214,17 @@ public class HandshakeWebSocketService implements WebSocketService, Lifecycle { } if (!"WebSocket".equalsIgnoreCase(headers.getUpgrade())) { - return handleBadRequest("Invalid 'Upgrade' header: " + headers); + return handleBadRequest(exchange, "Invalid 'Upgrade' header: " + headers); } List connectionValue = headers.getConnection(); if (!connectionValue.contains("Upgrade") && !connectionValue.contains("upgrade")) { - return handleBadRequest("Invalid 'Connection' header: " + headers); + return handleBadRequest(exchange, "Invalid 'Connection' header: " + headers); } String key = headers.getFirst(SEC_WEBSOCKET_KEY); if (key == null) { - return handleBadRequest("Missing \"Sec-WebSocket-Key\" header"); + return handleBadRequest(exchange, "Missing \"Sec-WebSocket-Key\" header"); } String protocol = selectProtocol(headers, handler); @@ -235,9 +235,9 @@ public class HandshakeWebSocketService implements WebSocketService, Lifecycle { ); } - private Mono handleBadRequest(String reason) { + private Mono handleBadRequest(ServerWebExchange exchange, String reason) { if (logger.isDebugEnabled()) { - logger.debug(reason); + logger.debug(exchange.getLogPrefix() + reason); } return Mono.error(new ServerWebInputException(reason)); }