From 28a5c3009ea0c31f879c0bb8b9e6cfd33faa81e5 Mon Sep 17 00:00:00 2001 From: Rossen Stoyanchev Date: Mon, 18 Jun 2018 17:48:55 -0400 Subject: [PATCH] Improve DEBUG/TRACE logging for Spring MVC Issue: SPR-16898 --- .../springframework/http/CacheControl.java | 4 + .../org/springframework/http/HttpStatus.java | 2 +- ...ractMappingContentNegotiationStrategy.java | 3 - .../FixedContentNegotiationStrategy.java | 3 - ...thExtensionContentNegotiationStrategy.java | 1 - .../bind/MethodArgumentNotValidException.java | 11 +- .../async/CallableInterceptorChain.java | 10 +- .../async/DeferredResultInterceptorChain.java | 8 +- .../request/async/WebAsyncManager.java | 18 +- .../web/cors/DefaultCorsProcessor.java | 4 +- .../support/InvocableHandlerMethod.java | 19 +- .../commons/CommonsFileUploadSupport.java | 25 ++- .../commons/CommonsMultipartFile.java | 13 +- .../multipart/support/MultipartFilter.java | 9 +- .../support/InvocableHandlerMethodTests.java | 2 +- .../web/servlet/DispatcherServlet.java | 172 +++++++++++------- .../web/servlet/FrameworkServlet.java | 22 ++- .../web/servlet/HandlerExecutionChain.java | 21 ++- .../web/servlet/HttpServletBean.java | 8 +- .../web/servlet/ModelAndView.java | 14 +- .../AbstractDetectingUrlHandlerMapping.java | 12 +- .../AbstractHandlerExceptionResolver.java | 8 +- .../handler/AbstractHandlerMapping.java | 25 ++- .../handler/AbstractHandlerMethodMapping.java | 64 +++---- .../handler/AbstractUrlHandlerMapping.java | 29 ++- .../SimpleMappingExceptionResolver.java | 11 +- .../handler/SimpleUrlHandlerMapping.java | 16 +- .../servlet/i18n/CookieLocaleResolver.java | 12 +- .../mvc/AbstractUrlViewController.java | 5 +- .../mvc/ParameterizableViewController.java | 41 ++++- .../mvc/ServletForwardingController.java | 8 +- .../servlet/mvc/WebContentInterceptor.java | 15 +- .../ResponseStatusExceptionResolver.java | 2 +- ...essageConverterMethodArgumentResolver.java | 8 +- ...stractMessageConverterMethodProcessor.java | 30 +-- .../ExceptionHandlerExceptionResolver.java | 25 +-- .../ExtendedServletRequestDataBinder.java | 2 +- .../annotation/MvcUriComponentsBuilder.java | 39 ++-- .../annotation/ReactiveTypeHandler.java | 8 +- .../RequestMappingHandlerAdapter.java | 41 +++-- .../RequestResponseBodyAdviceChain.java | 19 +- ...ResponseBodyEmitterReturnValueHandler.java | 4 +- .../ResponseEntityExceptionHandler.java | 6 +- .../ServletInvocableHandlerMethod.java | 4 +- .../DefaultHandlerExceptionResolver.java | 16 +- .../resource/AbstractResourceResolver.java | 7 - .../resource/AppCacheManifestTransformer.java | 18 +- .../resource/CachingResourceResolver.java | 10 +- .../resource/CachingResourceTransformer.java | 6 +- .../resource/CssLinkResourceTransformer.java | 19 +- .../resource/GzipResourceResolver.java | 2 +- .../resource/PathResourceResolver.java | 15 +- .../resource/ResourceHttpRequestHandler.java | 38 ++-- .../resource/ResourceUrlEncodingFilter.java | 3 +- .../servlet/resource/ResourceUrlProvider.java | 32 +--- .../resource/VersionResourceResolver.java | 18 +- .../support/AbstractFlashMapManager.java | 13 +- .../view/AbstractCachingViewResolver.java | 24 +-- .../servlet/view/AbstractTemplateView.java | 21 ++- .../web/servlet/view/AbstractView.java | 39 ++-- .../servlet/view/BeanNameViewResolver.java | 6 +- .../view/ContentNegotiatingViewResolver.java | 28 ++- .../servlet/view/InternalResourceView.java | 4 +- .../view/freemarker/FreeMarkerConfigurer.java | 2 +- .../view/freemarker/FreeMarkerView.java | 13 +- .../web/servlet/view/xslt/XsltView.java | 5 +- .../annotation/CglibProxyControllerTests.java | 6 +- .../ContentNegotiatingViewResolverTests.java | 3 + src/docs/asciidoc/web/webmvc.adoc | 36 ++-- 69 files changed, 585 insertions(+), 602 deletions(-) diff --git a/spring-web/src/main/java/org/springframework/http/CacheControl.java b/spring-web/src/main/java/org/springframework/http/CacheControl.java index ba092ee53f..5cf9873190 100644 --- a/spring-web/src/main/java/org/springframework/http/CacheControl.java +++ b/spring-web/src/main/java/org/springframework/http/CacheControl.java @@ -304,4 +304,8 @@ public class CacheControl { builder.append(value); } + @Override + public String toString() { + return "CacheControl [" + getHeaderValue() + "]"; + } } diff --git a/spring-web/src/main/java/org/springframework/http/HttpStatus.java b/spring-web/src/main/java/org/springframework/http/HttpStatus.java index e7b0f4aec5..d7d67b8224 100644 --- a/spring-web/src/main/java/org/springframework/http/HttpStatus.java +++ b/spring-web/src/main/java/org/springframework/http/HttpStatus.java @@ -504,7 +504,7 @@ public enum HttpStatus { */ @Override public String toString() { - return Integer.toString(this.value); + return Integer.toString(this.value) + " " + name(); } diff --git a/spring-web/src/main/java/org/springframework/web/accept/AbstractMappingContentNegotiationStrategy.java b/spring-web/src/main/java/org/springframework/web/accept/AbstractMappingContentNegotiationStrategy.java index 045e90297f..cbe5fd2fe3 100644 --- a/spring-web/src/main/java/org/springframework/web/accept/AbstractMappingContentNegotiationStrategy.java +++ b/spring-web/src/main/java/org/springframework/web/accept/AbstractMappingContentNegotiationStrategy.java @@ -138,9 +138,6 @@ public abstract class AbstractMappingContentNegotiationStrategy extends MappingM * {@link #lookupMediaType}. */ protected void handleMatch(String key, MediaType mediaType) { - if (logger.isTraceEnabled()) { - logger.trace("Requested MediaType='" + mediaType + "' based on key='" + key + "'."); - } } /** diff --git a/spring-web/src/main/java/org/springframework/web/accept/FixedContentNegotiationStrategy.java b/spring-web/src/main/java/org/springframework/web/accept/FixedContentNegotiationStrategy.java index 6c913f651b..e6caddfe2a 100644 --- a/spring-web/src/main/java/org/springframework/web/accept/FixedContentNegotiationStrategy.java +++ b/spring-web/src/main/java/org/springframework/web/accept/FixedContentNegotiationStrategy.java @@ -69,9 +69,6 @@ public class FixedContentNegotiationStrategy implements ContentNegotiationStrate @Override public List resolveMediaTypes(NativeWebRequest request) { - if (logger.isDebugEnabled()) { - logger.debug("Requested media types: " + this.contentTypes); - } return this.contentTypes; } diff --git a/spring-web/src/main/java/org/springframework/web/accept/PathExtensionContentNegotiationStrategy.java b/spring-web/src/main/java/org/springframework/web/accept/PathExtensionContentNegotiationStrategy.java index d9ebb00804..5663b92904 100644 --- a/spring-web/src/main/java/org/springframework/web/accept/PathExtensionContentNegotiationStrategy.java +++ b/spring-web/src/main/java/org/springframework/web/accept/PathExtensionContentNegotiationStrategy.java @@ -87,7 +87,6 @@ public class PathExtensionContentNegotiationStrategy extends AbstractMappingCont protected String getMediaTypeKey(NativeWebRequest webRequest) { HttpServletRequest request = webRequest.getNativeRequest(HttpServletRequest.class); if (request == null) { - logger.warn("An HttpServletRequest is required to determine the media type key"); return null; } String path = this.urlPathHelper.getLookupPathForRequest(request); diff --git a/spring-web/src/main/java/org/springframework/web/bind/MethodArgumentNotValidException.java b/spring-web/src/main/java/org/springframework/web/bind/MethodArgumentNotValidException.java index c8346a0558..3242878394 100644 --- a/spring-web/src/main/java/org/springframework/web/bind/MethodArgumentNotValidException.java +++ b/spring-web/src/main/java/org/springframework/web/bind/MethodArgumentNotValidException.java @@ -61,10 +61,13 @@ public class MethodArgumentNotValidException extends Exception { @Override public String getMessage() { - StringBuilder sb = new StringBuilder("Validation failed for argument at index ") - .append(this.parameter.getParameterIndex()).append(" in method: ") - .append(this.parameter.getExecutable().toGenericString()) - .append(", with ").append(this.bindingResult.getErrorCount()).append(" error(s): "); + StringBuilder sb = new StringBuilder("Validation failed for argument [") + .append(this.parameter.getParameterIndex()).append("] in ") + .append(this.parameter.getExecutable().toGenericString()); + if (this.bindingResult.getErrorCount() > 1) { + sb.append(" with ").append(this.bindingResult.getErrorCount()).append(" errors"); + } + sb.append(": "); for (ObjectError error : this.bindingResult.getAllErrors()) { sb.append("[").append(error).append("] "); } diff --git a/spring-web/src/main/java/org/springframework/web/context/request/async/CallableInterceptorChain.java b/spring-web/src/main/java/org/springframework/web/context/request/async/CallableInterceptorChain.java index ac87f56d6d..492d80cae2 100644 --- a/spring-web/src/main/java/org/springframework/web/context/request/async/CallableInterceptorChain.java +++ b/spring-web/src/main/java/org/springframework/web/context/request/async/CallableInterceptorChain.java @@ -72,13 +72,13 @@ class CallableInterceptorChain { try { this.interceptors.get(i).postProcess(request, task, concurrentResult); } - catch (Throwable t) { + catch (Throwable ex) { // Save the first exception but invoke all interceptors if (exceptionResult != null) { - logger.error("postProcess error", t); + logger.warn("Unhandled error from interceptor postProcess method", ex); } else { - exceptionResult = t; + exceptionResult = ex; } } } @@ -140,8 +140,8 @@ class CallableInterceptorChain { try { this.interceptors.get(i).afterCompletion(request, task); } - catch (Throwable t) { - logger.error("afterCompletion error", t); + catch (Throwable ex) { + logger.error("Unhandled error from interceptor afterCompletion method", ex); } } } diff --git a/spring-web/src/main/java/org/springframework/web/context/request/async/DeferredResultInterceptorChain.java b/spring-web/src/main/java/org/springframework/web/context/request/async/DeferredResultInterceptorChain.java index 5576e79b6a..98bc5c1adb 100644 --- a/spring-web/src/main/java/org/springframework/web/context/request/async/DeferredResultInterceptorChain.java +++ b/spring-web/src/main/java/org/springframework/web/context/request/async/DeferredResultInterceptorChain.java @@ -65,8 +65,8 @@ class DeferredResultInterceptorChain { this.interceptors.get(i).postProcess(request, deferredResult, concurrentResult); } } - catch (Throwable t) { - return t; + catch (Throwable ex) { + return ex; } return concurrentResult; } @@ -105,8 +105,8 @@ class DeferredResultInterceptorChain { try { this.interceptors.get(i).afterCompletion(request, deferredResult); } - catch (Throwable t) { - logger.error("afterCompletion error", t); + catch (Throwable ex) { + logger.error("Unhandled error from interceptor afterCompletion method", ex); } } } diff --git a/spring-web/src/main/java/org/springframework/web/context/request/async/WebAsyncManager.java b/spring-web/src/main/java/org/springframework/web/context/request/async/WebAsyncManager.java index a811a75b3d..d0bdeb2ca3 100644 --- a/spring-web/src/main/java/org/springframework/web/context/request/async/WebAsyncManager.java +++ b/spring-web/src/main/java/org/springframework/web/context/request/async/WebAsyncManager.java @@ -290,7 +290,7 @@ public final class WebAsyncManager { final CallableInterceptorChain interceptorChain = new CallableInterceptorChain(interceptors); this.asyncWebRequest.addTimeoutHandler(() -> { - logger.debug("Processing timeout"); + logger.debug("Async request timeout for " + formatRequestUri()); Object result = interceptorChain.triggerAfterTimeout(this.asyncWebRequest, callable); if (result != CallableProcessingInterceptor.RESULT_NONE) { setConcurrentResultAndDispatch(result); @@ -298,7 +298,7 @@ public final class WebAsyncManager { }); this.asyncWebRequest.addErrorHandler(ex -> { - logger.debug("Processing error"); + logger.debug("Async request error for " + formatRequestUri() + ": " + ex); Object result = interceptorChain.triggerAfterError(this.asyncWebRequest, callable, ex); result = (result != CallableProcessingInterceptor.RESULT_NONE ? result : ex); setConcurrentResultAndDispatch(result); @@ -333,6 +333,11 @@ public final class WebAsyncManager { } } + private String formatRequestUri() { + HttpServletRequest request = this.asyncWebRequest.getNativeRequest(HttpServletRequest.class); + return request != null ? urlPathHelper.getRequestUri(request) : "servlet container"; + } + private void setConcurrentResultAndDispatch(Object result) { synchronized (WebAsyncManager.this) { if (this.concurrentResult != RESULT_NONE) { @@ -347,8 +352,7 @@ public final class WebAsyncManager { } if (logger.isDebugEnabled()) { - logger.debug("Concurrent result value [" + this.concurrentResult + - "] - dispatching request to resume processing"); + logger.debug("Async result ready, dispatch to " + formatRequestUri()); } this.asyncWebRequest.dispatch(); } @@ -432,11 +436,7 @@ public final class WebAsyncManager { this.asyncWebRequest.startAsync(); if (logger.isDebugEnabled()) { - HttpServletRequest request = this.asyncWebRequest.getNativeRequest(HttpServletRequest.class); - if (request != null) { - String requestUri = urlPathHelper.getRequestUri(request); - logger.debug("Concurrent handling starting for " + request.getMethod() + " [" + requestUri + "]"); - } + logger.debug("Started async request"); } } diff --git a/spring-web/src/main/java/org/springframework/web/cors/DefaultCorsProcessor.java b/spring-web/src/main/java/org/springframework/web/cors/DefaultCorsProcessor.java index f964afd081..ea7ddb0771 100644 --- a/spring-web/src/main/java/org/springframework/web/cors/DefaultCorsProcessor.java +++ b/spring-web/src/main/java/org/springframework/web/cors/DefaultCorsProcessor.java @@ -68,13 +68,13 @@ public class DefaultCorsProcessor implements CorsProcessor { ServletServerHttpResponse serverResponse = new ServletServerHttpResponse(response); if (responseHasCors(serverResponse)) { - logger.debug("Skip CORS processing: response already contains \"Access-Control-Allow-Origin\" header"); + logger.trace("Skip CORS processing: response already contains \"Access-Control-Allow-Origin\" header"); return true; } ServletServerHttpRequest serverRequest = new ServletServerHttpRequest(request); if (WebUtils.isSameOrigin(serverRequest)) { - logger.debug("Skip CORS processing: request is from same origin"); + logger.trace("Skip CORS processing: request is from same origin"); return true; } diff --git a/spring-web/src/main/java/org/springframework/web/method/support/InvocableHandlerMethod.java b/spring-web/src/main/java/org/springframework/web/method/support/InvocableHandlerMethod.java index 694c51d47b..88c17aa7ec 100644 --- a/spring-web/src/main/java/org/springframework/web/method/support/InvocableHandlerMethod.java +++ b/spring-web/src/main/java/org/springframework/web/method/support/InvocableHandlerMethod.java @@ -26,6 +26,7 @@ import org.springframework.core.ParameterNameDiscoverer; import org.springframework.lang.Nullable; import org.springframework.util.ClassUtils; import org.springframework.util.ReflectionUtils; +import org.springframework.util.StringUtils; import org.springframework.web.bind.WebDataBinder; import org.springframework.web.bind.support.SessionStatus; import org.springframework.web.bind.support.WebDataBinderFactory; @@ -163,24 +164,26 @@ public class InvocableHandlerMethod extends HandlerMethod { continue; } catch (Exception ex) { - if (logger.isDebugEnabled()) { - logger.debug(getArgumentResolutionErrorMessage("Failed to resolve", i), ex); + // Leave stack trace for later, e.g. AbstractHandlerExceptionResolver + String message = ex.getMessage(); + if (!message.contains(parameter.getExecutable().toGenericString())) { + if (logger.isDebugEnabled()) { + logger.debug(formatArgumentError(parameter, message)); + } } throw ex; } } if (args[i] == null) { - throw new IllegalStateException("Could not resolve method parameter at index " + - parameter.getParameterIndex() + " in " + parameter.getExecutable().toGenericString() + - ": " + getArgumentResolutionErrorMessage("No suitable resolver for", i)); + throw new IllegalStateException(formatArgumentError(parameter, "No suitable resolver")); } } return args; } - private String getArgumentResolutionErrorMessage(String text, int index) { - Class paramType = getMethodParameters()[index].getParameterType(); - return text + " argument " + index + " of type '" + paramType.getName() + "'"; + private static String formatArgumentError(MethodParameter param, String message) { + return "Could not resolve parameter [" + param.getParameterIndex() + "] in " + + param.getExecutable().toGenericString() + (StringUtils.hasText(message) ? ": " + message : ""); } /** diff --git a/spring-web/src/main/java/org/springframework/web/multipart/commons/CommonsFileUploadSupport.java b/spring-web/src/main/java/org/springframework/web/multipart/commons/CommonsFileUploadSupport.java index f9ed7fb086..4c4bd2de49 100644 --- a/spring-web/src/main/java/org/springframework/web/multipart/commons/CommonsFileUploadSupport.java +++ b/spring-web/src/main/java/org/springframework/web/multipart/commons/CommonsFileUploadSupport.java @@ -281,10 +281,15 @@ public abstract class CommonsFileUploadSupport { // multipart file field CommonsMultipartFile file = createMultipartFile(fileItem); multipartFiles.add(file.getName(), file); - if (logger.isDebugEnabled()) { - logger.debug("Found multipart file [" + file.getName() + "] of size " + file.getSize() + - " bytes with original filename [" + file.getOriginalFilename() + "], stored " + - file.getStorageDescription()); + if (logger.isDebugEnabled() || logger.isTraceEnabled()) { + String message = "Part '" + file.getName() + "', " + + "size " + file.getSize() + " bytes, filename='" + file.getOriginalFilename() + "'"; + if (logger.isTraceEnabled()) { + logger.trace(message + ", storage=" + file.getStorageDescription()); + } + else { + logger.debug(message); + } } } } @@ -318,9 +323,15 @@ public abstract class CommonsFileUploadSupport { if (file instanceof CommonsMultipartFile) { CommonsMultipartFile cmf = (CommonsMultipartFile) file; cmf.getFileItem().delete(); - if (logger.isDebugEnabled()) { - logger.debug("Cleaning up multipart file [" + cmf.getName() + "] with original filename [" + - cmf.getOriginalFilename() + "], stored " + cmf.getStorageDescription()); + if (logger.isDebugEnabled() || logger.isTraceEnabled()) { + String filename = cmf.getOriginalFilename(); + String message = "Cleaning up part '" + cmf.getName() + "', filename '" + filename + "'"; + if (logger.isTraceEnabled()) { + logger.trace(message + ", stored " + cmf.getStorageDescription()); + } + else { + logger.debug(message); + } } } } diff --git a/spring-web/src/main/java/org/springframework/web/multipart/commons/CommonsMultipartFile.java b/spring-web/src/main/java/org/springframework/web/multipart/commons/CommonsMultipartFile.java index e1c9585e7e..9a807ff89f 100644 --- a/spring-web/src/main/java/org/springframework/web/multipart/commons/CommonsMultipartFile.java +++ b/spring-web/src/main/java/org/springframework/web/multipart/commons/CommonsMultipartFile.java @@ -165,14 +165,19 @@ public class CommonsMultipartFile implements MultipartFile, Serializable { try { this.fileItem.write(dest); - if (logger.isDebugEnabled()) { + if (logger.isDebugEnabled() || logger.isTraceEnabled()) { String action = "transferred"; if (!this.fileItem.isInMemory()) { action = (isAvailable() ? "copied" : "moved"); } - logger.debug("Multipart file '" + getName() + "' with original filename [" + - getOriginalFilename() + "], stored " + getStorageDescription() + ": " + - action + " to [" + dest.getAbsolutePath() + "]"); + String message = "Part '" + getName() + "', filename '" + getOriginalFilename() + "'"; + if (logger.isTraceEnabled()) { + logger.trace(message + ", stored " + getStorageDescription() + ": " + action + + " to [" + dest.getAbsolutePath() + "]"); + } + else { + logger.debug(message + ": " + action + " to [" + dest.getAbsolutePath() + "]"); + } } } catch (FileUploadException ex) { diff --git a/spring-web/src/main/java/org/springframework/web/multipart/support/MultipartFilter.java b/spring-web/src/main/java/org/springframework/web/multipart/support/MultipartFilter.java index 11d202b663..10f1f9b99b 100644 --- a/spring-web/src/main/java/org/springframework/web/multipart/support/MultipartFilter.java +++ b/spring-web/src/main/java/org/springframework/web/multipart/support/MultipartFilter.java @@ -106,16 +106,15 @@ public class MultipartFilter extends OncePerRequestFilter { HttpServletRequest processedRequest = request; if (multipartResolver.isMultipart(processedRequest)) { - if (logger.isDebugEnabled()) { - logger.debug("Resolving multipart request [" + processedRequest.getRequestURI() + - "] with MultipartFilter"); + if (logger.isTraceEnabled()) { + logger.trace("Resolving multipart request"); } processedRequest = multipartResolver.resolveMultipart(processedRequest); } else { // A regular request... - if (logger.isDebugEnabled()) { - logger.debug("Request [" + processedRequest.getRequestURI() + "] is not a multipart request"); + if (logger.isTraceEnabled()) { + logger.trace("Not a multipart request"); } } diff --git a/spring-web/src/test/java/org/springframework/web/method/support/InvocableHandlerMethodTests.java b/spring-web/src/test/java/org/springframework/web/method/support/InvocableHandlerMethodTests.java index f64fdde463..d1e0cd3a4d 100644 --- a/spring-web/src/test/java/org/springframework/web/method/support/InvocableHandlerMethodTests.java +++ b/spring-web/src/test/java/org/springframework/web/method/support/InvocableHandlerMethodTests.java @@ -93,7 +93,7 @@ public class InvocableHandlerMethodTests { fail("Expected exception"); } catch (IllegalStateException ex) { - assertTrue(ex.getMessage().contains("No suitable resolver for argument 0 of type 'java.lang.Integer'")); + assertTrue(ex.getMessage().contains("Could not resolve parameter [0]")); } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/DispatcherServlet.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/DispatcherServlet.java index 9df3010930..cb09c67377 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/DispatcherServlet.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/DispatcherServlet.java @@ -18,6 +18,7 @@ package org.springframework.web.servlet; import java.io.IOException; import java.util.ArrayList; +import java.util.Arrays; import java.util.Collections; import java.util.Enumeration; import java.util.HashMap; @@ -28,6 +29,8 @@ import java.util.Locale; import java.util.Map; import java.util.Properties; import java.util.Set; +import java.util.stream.Collectors; +import javax.servlet.DispatcherType; import javax.servlet.ServletContext; import javax.servlet.ServletException; import javax.servlet.http.HttpServletRequest; @@ -514,16 +517,18 @@ public class DispatcherServlet extends FrameworkServlet { private void initMultipartResolver(ApplicationContext context) { try { this.multipartResolver = context.getBean(MULTIPART_RESOLVER_BEAN_NAME, MultipartResolver.class); - if (logger.isDebugEnabled()) { - logger.debug("Using MultipartResolver [" + this.multipartResolver + "]"); + if (logger.isTraceEnabled()) { + logger.trace("Detected " + this.multipartResolver); + } + else if (logger.isDebugEnabled()) { + logger.debug("Detected " + this.multipartResolver.getClass().getSimpleName()); } } catch (NoSuchBeanDefinitionException ex) { // Default is no multipart resolver. this.multipartResolver = null; - if (logger.isDebugEnabled()) { - logger.debug("Unable to locate MultipartResolver with name '" + MULTIPART_RESOLVER_BEAN_NAME + - "': no multipart request handling provided"); + if (logger.isTraceEnabled()) { + logger.trace("No MultipartResolver '" + MULTIPART_RESOLVER_BEAN_NAME + "' declared"); } } } @@ -536,16 +541,19 @@ public class DispatcherServlet extends FrameworkServlet { private void initLocaleResolver(ApplicationContext context) { try { this.localeResolver = context.getBean(LOCALE_RESOLVER_BEAN_NAME, LocaleResolver.class); - if (logger.isDebugEnabled()) { - logger.debug("Using LocaleResolver [" + this.localeResolver + "]"); + if (logger.isTraceEnabled()) { + logger.trace("Detected " + this.localeResolver); + } + else if (logger.isDebugEnabled()) { + logger.debug("Detected " + this.localeResolver.getClass().getSimpleName()); } } catch (NoSuchBeanDefinitionException ex) { // We need to use the default. this.localeResolver = getDefaultStrategy(context, LocaleResolver.class); - if (logger.isDebugEnabled()) { - logger.debug("Unable to locate LocaleResolver with name '" + LOCALE_RESOLVER_BEAN_NAME + - "': using default [" + this.localeResolver + "]"); + if (logger.isTraceEnabled()) { + logger.trace("No LocaleResolver '" + LOCALE_RESOLVER_BEAN_NAME + + "': using default [" + this.localeResolver.getClass().getSimpleName() + "]"); } } } @@ -558,16 +566,19 @@ public class DispatcherServlet extends FrameworkServlet { private void initThemeResolver(ApplicationContext context) { try { this.themeResolver = context.getBean(THEME_RESOLVER_BEAN_NAME, ThemeResolver.class); - if (logger.isDebugEnabled()) { - logger.debug("Using ThemeResolver [" + this.themeResolver + "]"); + if (logger.isTraceEnabled()) { + logger.trace("Detected " + this.themeResolver); + } + else if (logger.isDebugEnabled()) { + logger.debug("Detected " + this.themeResolver.getClass().getSimpleName()); } } catch (NoSuchBeanDefinitionException ex) { // We need to use the default. this.themeResolver = getDefaultStrategy(context, ThemeResolver.class); - if (logger.isDebugEnabled()) { - logger.debug("Unable to locate ThemeResolver with name '" + THEME_RESOLVER_BEAN_NAME + - "': using default [" + this.themeResolver + "]"); + if (logger.isTraceEnabled()) { + logger.trace("No ThemeResolver '" + THEME_RESOLVER_BEAN_NAME + + "': using default [" + this.themeResolver.getClass().getSimpleName() + "]"); } } } @@ -604,8 +615,9 @@ public class DispatcherServlet extends FrameworkServlet { // a default HandlerMapping if no other mappings are found. if (this.handlerMappings == null) { this.handlerMappings = getDefaultStrategies(context, HandlerMapping.class); - if (logger.isDebugEnabled()) { - logger.debug("No HandlerMappings found in servlet '" + getServletName() + "': using default"); + if (logger.isTraceEnabled()) { + logger.trace("No HandlerMappings declared for servlet '" + getServletName() + + "': using default strategies from DispatcherServlet.properties"); } } } @@ -642,8 +654,9 @@ public class DispatcherServlet extends FrameworkServlet { // default HandlerAdapters if no other adapters are found. if (this.handlerAdapters == null) { this.handlerAdapters = getDefaultStrategies(context, HandlerAdapter.class); - if (logger.isDebugEnabled()) { - logger.debug("No HandlerAdapters found in servlet '" + getServletName() + "': using default"); + if (logger.isTraceEnabled()) { + logger.trace("No HandlerAdapters declared for servlet '" + getServletName() + + "': using default strategies from DispatcherServlet.properties"); } } } @@ -681,8 +694,9 @@ public class DispatcherServlet extends FrameworkServlet { // default HandlerExceptionResolvers if no other resolvers are found. if (this.handlerExceptionResolvers == null) { this.handlerExceptionResolvers = getDefaultStrategies(context, HandlerExceptionResolver.class); - if (logger.isDebugEnabled()) { - logger.debug("No HandlerExceptionResolvers found in servlet '" + getServletName() + "': using default"); + if (logger.isTraceEnabled()) { + logger.trace("No HandlerExceptionResolvers declared in servlet '" + getServletName() + + "': using default strategies from DispatcherServlet.properties"); } } } @@ -695,17 +709,19 @@ public class DispatcherServlet extends FrameworkServlet { try { this.viewNameTranslator = context.getBean(REQUEST_TO_VIEW_NAME_TRANSLATOR_BEAN_NAME, RequestToViewNameTranslator.class); - if (logger.isDebugEnabled()) { - logger.debug("Using RequestToViewNameTranslator [" + this.viewNameTranslator + "]"); + if (logger.isTraceEnabled()) { + logger.trace("Detected " + this.viewNameTranslator.getClass().getSimpleName()); + } + else if (logger.isDebugEnabled()) { + logger.debug("Detected " + this.viewNameTranslator); } } catch (NoSuchBeanDefinitionException ex) { // We need to use the default. this.viewNameTranslator = getDefaultStrategy(context, RequestToViewNameTranslator.class); - if (logger.isDebugEnabled()) { - logger.debug("Unable to locate RequestToViewNameTranslator with name '" + - REQUEST_TO_VIEW_NAME_TRANSLATOR_BEAN_NAME + "': using default [" + this.viewNameTranslator + - "]"); + if (logger.isTraceEnabled()) { + logger.trace("No RequestToViewNameTranslator '" + REQUEST_TO_VIEW_NAME_TRANSLATOR_BEAN_NAME + + "': using default [" + this.viewNameTranslator.getClass().getSimpleName() + "]"); } } } @@ -742,8 +758,9 @@ public class DispatcherServlet extends FrameworkServlet { // a default ViewResolver if no other resolvers are found. if (this.viewResolvers == null) { this.viewResolvers = getDefaultStrategies(context, ViewResolver.class); - if (logger.isDebugEnabled()) { - logger.debug("No ViewResolvers found in servlet '" + getServletName() + "': using default"); + if (logger.isTraceEnabled()) { + logger.trace("No ViewResolvers declared for servlet '" + getServletName() + + "': using default strategies from DispatcherServlet.properties"); } } } @@ -756,16 +773,19 @@ public class DispatcherServlet extends FrameworkServlet { private void initFlashMapManager(ApplicationContext context) { try { this.flashMapManager = context.getBean(FLASH_MAP_MANAGER_BEAN_NAME, FlashMapManager.class); - if (logger.isDebugEnabled()) { - logger.debug("Using FlashMapManager [" + this.flashMapManager + "]"); + if (logger.isTraceEnabled()) { + logger.trace("Detected " + this.flashMapManager.getClass().getSimpleName()); + } + else if (logger.isDebugEnabled()) { + logger.debug("Detected " + this.flashMapManager); } } catch (NoSuchBeanDefinitionException ex) { // We need to use the default. this.flashMapManager = getDefaultStrategy(context, FlashMapManager.class); - if (logger.isDebugEnabled()) { - logger.debug("Unable to locate FlashMapManager with name '" + - FLASH_MAP_MANAGER_BEAN_NAME + "': using default [" + this.flashMapManager + "]"); + if (logger.isTraceEnabled()) { + logger.trace("No FlashMapManager '" + FLASH_MAP_MANAGER_BEAN_NAME + + "': using default [" + this.flashMapManager.getClass().getSimpleName() + "]"); } } } @@ -886,11 +906,8 @@ public class DispatcherServlet extends FrameworkServlet { */ @Override protected void doService(HttpServletRequest request, HttpServletResponse response) throws Exception { - if (logger.isDebugEnabled()) { - String resumed = WebAsyncUtils.getAsyncManager(request).hasConcurrentResult() ? " resumed" : ""; - logger.debug("DispatcherServlet with name '" + getServletName() + "'" + resumed + - " processing " + request.getMethod() + " request for [" + getRequestUri(request) + "]"); - } + + logRequest(request); // Keep a snapshot of the request attributes in case of an include, // to be able to restore the original attributes after the include. @@ -934,6 +951,31 @@ public class DispatcherServlet extends FrameworkServlet { } } + private void logRequest(HttpServletRequest request) { + if (logger.isDebugEnabled() || logger.isTraceEnabled()) { + + String params = request.getParameterMap().entrySet().stream() + .map(entry -> entry.getKey() + ":" + Arrays.toString(entry.getValue())) + .collect(Collectors.joining(", ", ", parameters={", "}")); + + String dispatchType = !request.getDispatcherType().equals(DispatcherType.REQUEST) ? + " [" + request.getDispatcherType().name() + "]" : ""; + + String message = request.getMethod() + " " + getRequestUri(request) + dispatchType + params; + + if (logger.isTraceEnabled()) { + String headers = Collections.list(request.getHeaderNames()).stream() + .map(name -> name + ":" + Collections.list(request.getHeaders(name))) + .collect(Collectors.joining(", ", ", headers={", "}")); + + logger.trace(message + headers + " in DispatcherServlet '" + getServletName() + "'"); + } + else { + logger.debug(message); + } + } + } + /** * Process the actual dispatching to the handler. *

The handler will be obtained by applying the servlet's HandlerMappings in order. @@ -975,9 +1017,6 @@ public class DispatcherServlet extends FrameworkServlet { boolean isGet = "GET".equals(method); if (isGet || "HEAD".equals(method)) { long lastModified = ha.getLastModified(request, mappedHandler.getHandler()); - if (logger.isDebugEnabled()) { - logger.debug("Last-Modified value for [" + getRequestUri(request) + "] is: " + lastModified); - } if (new ServletWebRequest(request, response).checkNotModified(lastModified) && isGet) { return; } @@ -1072,9 +1111,8 @@ public class DispatcherServlet extends FrameworkServlet { } } else { - if (logger.isDebugEnabled()) { - logger.debug("Null ModelAndView returned to DispatcherServlet with name '" + getServletName() + - "': assuming HandlerAdapter completed request handling"); + if (logger.isTraceEnabled()) { + logger.trace("No view rendering, null ModelAndView returned."); } } @@ -1116,11 +1154,12 @@ public class DispatcherServlet extends FrameworkServlet { protected HttpServletRequest checkMultipart(HttpServletRequest request) throws MultipartException { if (this.multipartResolver != null && this.multipartResolver.isMultipart(request)) { if (WebUtils.getNativeRequest(request, MultipartHttpServletRequest.class) != null) { - logger.debug("Request is already a MultipartHttpServletRequest - if not in a forward, " + - "this typically results from an additional MultipartFilter in web.xml"); + if (request.getDispatcherType().equals(DispatcherType.REQUEST)) { + logger.trace("Request already resolved to MultipartHttpServletRequest, e.g. by MultipartFilter"); + } } else if (hasMultipartException(request) ) { - logger.debug("Multipart resolution failed for current request before - " + + logger.debug("Multipart resolution previously failed for current request - " + "skipping re-resolution for undisturbed error rendering"); } else { @@ -1180,12 +1219,8 @@ public class DispatcherServlet extends FrameworkServlet { @Nullable protected HandlerExecutionChain getHandler(HttpServletRequest request) throws Exception { if (this.handlerMappings != null) { - for (HandlerMapping hm : this.handlerMappings) { - if (logger.isTraceEnabled()) { - logger.trace( - "Testing handler map [" + hm + "] in DispatcherServlet with name '" + getServletName() + "'"); - } - HandlerExecutionChain handler = hm.getHandler(request); + for (HandlerMapping mapping : this.handlerMappings) { + HandlerExecutionChain handler = mapping.getHandler(request); if (handler != null) { return handler; } @@ -1202,8 +1237,8 @@ public class DispatcherServlet extends FrameworkServlet { */ protected void noHandlerFound(HttpServletRequest request, HttpServletResponse response) throws Exception { if (pageNotFoundLogger.isWarnEnabled()) { - pageNotFoundLogger.warn("No mapping found for HTTP request with URI [" + getRequestUri(request) + - "] in DispatcherServlet with name '" + getServletName() + "'"); + pageNotFoundLogger.warn("No mapping for " + request.getMethod() + " " + + getRequestUri(request) + " in DispatcherServlet '" + getServletName() + "'"); } if (this.throwExceptionIfNoHandlerFound) { throw new NoHandlerFoundException(request.getMethod(), getRequestUri(request), @@ -1221,12 +1256,9 @@ public class DispatcherServlet extends FrameworkServlet { */ protected HandlerAdapter getHandlerAdapter(Object handler) throws ServletException { if (this.handlerAdapters != null) { - for (HandlerAdapter ha : this.handlerAdapters) { - if (logger.isTraceEnabled()) { - logger.trace("Testing handler adapter [" + ha + "]"); - } - if (ha.supports(handler)) { - return ha; + for (HandlerAdapter adapter : this.handlerAdapters) { + if (adapter.supports(handler)) { + return adapter; } } } @@ -1254,8 +1286,8 @@ public class DispatcherServlet extends FrameworkServlet { // Check registered HandlerExceptionResolvers... ModelAndView exMv = null; if (this.handlerExceptionResolvers != null) { - for (HandlerExceptionResolver handlerExceptionResolver : this.handlerExceptionResolvers) { - exMv = handlerExceptionResolver.resolveException(request, response, handler, ex); + for (HandlerExceptionResolver resolver : this.handlerExceptionResolvers) { + exMv = resolver.resolveException(request, response, handler, ex); if (exMv != null) { break; } @@ -1273,8 +1305,11 @@ public class DispatcherServlet extends FrameworkServlet { exMv.setViewName(defaultViewName); } } + if (logger.isTraceEnabled()) { + logger.trace("Using resolved error view: " + exMv, ex); + } if (logger.isDebugEnabled()) { - logger.debug("Handler execution resulted in exception - forwarding to resolved error view: " + exMv, ex); + logger.debug("Using resolved error view: " + exMv); } WebUtils.exposeErrorRequestAttributes(request, ex, getServletName()); return exMv; @@ -1318,8 +1353,8 @@ public class DispatcherServlet extends FrameworkServlet { } // Delegate to the View object for rendering. - if (logger.isDebugEnabled()) { - logger.debug("Rendering view [" + view + "] in DispatcherServlet with name '" + getServletName() + "'"); + if (logger.isTraceEnabled()) { + logger.trace("Rendering view [" + view + "] "); } try { if (mv.getStatus() != null) { @@ -1329,8 +1364,7 @@ public class DispatcherServlet extends FrameworkServlet { } catch (Exception ex) { if (logger.isDebugEnabled()) { - logger.debug("Error rendering view [" + view + "] in DispatcherServlet with name '" + - getServletName() + "'", ex); + logger.debug("Error rendering view [" + view + "]", ex); } throw ex; } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/FrameworkServlet.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/FrameworkServlet.java index efb8498c8c..88cfc0fabd 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/FrameworkServlet.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/FrameworkServlet.java @@ -43,6 +43,7 @@ import org.springframework.core.GenericTypeResolver; import org.springframework.core.annotation.AnnotationAwareOrderComparator; import org.springframework.core.env.ConfigurableEnvironment; import org.springframework.http.HttpMethod; +import org.springframework.http.HttpStatus; import org.springframework.lang.Nullable; import org.springframework.util.ClassUtils; import org.springframework.util.ObjectUtils; @@ -565,9 +566,9 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic // Publish the context as a servlet context attribute. String attrName = getServletContextAttributeName(); getServletContext().setAttribute(attrName, wac); - if (this.logger.isDebugEnabled()) { - this.logger.debug("Published WebApplicationContext of servlet '" + getServletName() + - "' as ServletContext attribute with name [" + attrName + "]"); + if (this.logger.isTraceEnabled()) { + this.logger.trace("Published WebApplicationContext of servlet '" + getServletName() + + "' as ServletContext attribute [" + attrName + "]"); } } @@ -615,10 +616,10 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic */ protected WebApplicationContext createWebApplicationContext(@Nullable ApplicationContext parent) { Class contextClass = getContextClass(); - if (this.logger.isDebugEnabled()) { - this.logger.debug("Servlet with name '" + getServletName() + - "' will try to create custom WebApplicationContext context of class '" + - contextClass.getName() + "'" + ", using parent context [" + parent + "]"); + if (this.logger.isTraceEnabled()) { + this.logger.trace("Servlet '" + getServletName() + + "' will create custom WebApplicationContext context of class '" + + contextClass.getName() + "'" + ", parent context [" + parent + "]"); } if (!ConfigurableWebApplicationContext.class.isAssignableFrom(contextClass)) { throw new ApplicationContextException( @@ -990,14 +991,15 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic if (logger.isDebugEnabled()) { if (failureCause != null) { - this.logger.debug("Could not complete request", failureCause); + this.logger.debug("Failed to complete request: ", failureCause); } else { if (asyncManager.isConcurrentHandlingStarted()) { - logger.debug("Leaving response open for concurrent processing"); + logger.debug("Exiting, but response remains open for further handling"); } else { - this.logger.debug("Successfully completed request"); + HttpStatus status = HttpStatus.resolve(response.getStatus()); + this.logger.debug("Completed " + (status != null ? status : response.getStatus())); } } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/HandlerExecutionChain.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/HandlerExecutionChain.java index 6c58f5dbc4..4e9c7dd75e 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/HandlerExecutionChain.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/HandlerExecutionChain.java @@ -17,6 +17,7 @@ package org.springframework.web.servlet; import java.util.ArrayList; +import java.util.Arrays; import java.util.List; import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; @@ -202,21 +203,23 @@ public class HandlerExecutionChain { /** - * Delegates to the handler's {@code toString()}. + * Delegates to the handler and interceptors' {@code toString()}. */ @Override public String toString() { Object handler = getHandler(); StringBuilder sb = new StringBuilder(); - sb.append("HandlerExecutionChain with handler [").append(handler).append("]"); - HandlerInterceptor[] interceptors = getInterceptors(); - if (!ObjectUtils.isEmpty(interceptors)) { - sb.append(" and ").append(interceptors.length).append(" interceptor"); - if (interceptors.length > 1) { - sb.append("s"); - } + sb.append("HandlerExecutionChain with [").append(handler).append("] and "); + if (this.interceptorList != null) { + sb.append(this.interceptorList.size()); } - return sb.toString(); + else if (this.interceptors != null) { + sb.append(this.interceptors.length); + } + else { + sb.append(0); + } + return sb.append(" interceptors").toString(); } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/HttpServletBean.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/HttpServletBean.java index 598ff76269..f500a5e2ad 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/HttpServletBean.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/HttpServletBean.java @@ -146,8 +146,8 @@ public abstract class HttpServletBean extends HttpServlet implements Environment */ @Override public final void init() throws ServletException { - if (logger.isDebugEnabled()) { - logger.debug("Initializing servlet '" + getServletName() + "'"); + if (logger.isTraceEnabled()) { + logger.trace("Initializing servlet '" + getServletName() + "'"); } // Set bean properties from init parameters. @@ -171,8 +171,8 @@ public abstract class HttpServletBean extends HttpServlet implements Environment // Let subclasses do whatever initialization they like. initServletBean(); - if (logger.isDebugEnabled()) { - logger.debug("Servlet '" + getServletName() + "' configured successfully"); + if (logger.isTraceEnabled()) { + logger.trace("Servlet '" + getServletName() + "' configured successfully"); } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/ModelAndView.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/ModelAndView.java index 6902e70af8..a62123332b 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/ModelAndView.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/ModelAndView.java @@ -352,15 +352,11 @@ public class ModelAndView { */ @Override public String toString() { - StringBuilder sb = new StringBuilder("ModelAndView: "); - if (isReference()) { - sb.append("reference to view with name '").append(this.view).append("'"); - } - else { - sb.append("materialized View is [").append(this.view).append(']'); - } - sb.append("; model is ").append(this.model); - return sb.toString(); + return "ModelAndView [view=" + formatView() + "; model=" + this.model + "]"; + } + + private String formatView() { + return isReference() ? "\"" + this.view + "\"" : "[" + this.view + "]"; } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractDetectingUrlHandlerMapping.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractDetectingUrlHandlerMapping.java index 132ff4a8fd..40fa32bb20 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractDetectingUrlHandlerMapping.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractDetectingUrlHandlerMapping.java @@ -69,9 +69,6 @@ public abstract class AbstractDetectingUrlHandlerMapping extends AbstractUrlHand */ protected void detectHandlers() throws BeansException { ApplicationContext applicationContext = obtainApplicationContext(); - if (logger.isDebugEnabled()) { - logger.debug("Looking for URL mappings in application context: " + applicationContext); - } String[] beanNames = (this.detectHandlersInAncestorContexts ? BeanFactoryUtils.beanNamesForTypeIncludingAncestors(applicationContext, Object.class) : applicationContext.getBeanNamesForType(Object.class)); @@ -83,11 +80,10 @@ public abstract class AbstractDetectingUrlHandlerMapping extends AbstractUrlHand // URL paths found: Let's consider it a handler. registerHandler(urls, beanName); } - else { - if (logger.isDebugEnabled()) { - logger.debug("Rejected bean name '" + beanName + "': no URL paths identified"); - } - } + } + + if ((logger.isDebugEnabled() && !getHandlerMap().isEmpty()) || logger.isTraceEnabled()) { + logger.debug("Detected " + getHandlerMap().size() + " mappings in " + formatMappingName()); } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractHandlerExceptionResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractHandlerExceptionResolver.java index 964411c6db..9899fc9f25 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractHandlerExceptionResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractHandlerExceptionResolver.java @@ -132,12 +132,14 @@ public abstract class AbstractHandlerExceptionResolver implements HandlerExcepti HttpServletRequest request, HttpServletResponse response, @Nullable Object handler, Exception ex) { if (shouldApplyTo(request, handler)) { - if (this.logger.isDebugEnabled()) { - this.logger.debug("Resolving exception from handler [" + handler + "]: " + ex); - } prepareResponse(ex, response); ModelAndView result = doResolveException(request, response, handler, ex); if (result != null) { + // One-liner at debug level.. + if (logger.isDebugEnabled()) { + logger.debug("Resolved [" + ex + "]" + (result.isEmpty() ? "" : " to " + result)); + } + // warnLogger with full stack trace (requires explicit config).. logException(ex, request); } return result; diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractHandlerMapping.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractHandlerMapping.java index 8f05d0cccb..efbba4d384 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractHandlerMapping.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractHandlerMapping.java @@ -26,6 +26,7 @@ import javax.servlet.http.HttpServletResponse; import org.springframework.beans.BeansException; import org.springframework.beans.factory.BeanFactoryUtils; +import org.springframework.beans.factory.BeanNameAware; import org.springframework.core.Ordered; import org.springframework.lang.Nullable; import org.springframework.util.AntPathMatcher; @@ -65,7 +66,8 @@ import org.springframework.web.util.UrlPathHelper; * @see #setInterceptors * @see org.springframework.web.servlet.HandlerInterceptor */ -public abstract class AbstractHandlerMapping extends WebApplicationObjectSupport implements HandlerMapping, Ordered { +public abstract class AbstractHandlerMapping extends WebApplicationObjectSupport + implements HandlerMapping, Ordered, BeanNameAware { @Nullable private Object defaultHandler; @@ -84,6 +86,9 @@ public abstract class AbstractHandlerMapping extends WebApplicationObjectSupport private int order = Ordered.LOWEST_PRECEDENCE; // default: same as non-Ordered + @Nullable + private String beanName; + /** * Set the default handler for this handler mapping. @@ -231,6 +236,15 @@ public abstract class AbstractHandlerMapping extends WebApplicationObjectSupport return this.order; } + @Override + public void setBeanName(String name) { + this.beanName = name; + } + + protected String formatMappingName() { + return this.beanName != null ? "'" + this.beanName + "'" : ""; + } + /** * Initializes the interceptors. @@ -361,12 +375,21 @@ public abstract class AbstractHandlerMapping extends WebApplicationObjectSupport } HandlerExecutionChain executionChain = getHandlerExecutionChain(handler, request); + + if (logger.isTraceEnabled()) { + logger.trace("Mapped to " + handler); + } + else if (logger.isDebugEnabled()) { + logger.debug("Mapped to " + executionChain.getHandler()); + } + if (CorsUtils.isCorsRequest(request)) { CorsConfiguration globalConfig = this.globalCorsConfigSource.getCorsConfiguration(request); CorsConfiguration handlerConfig = getCorsConfiguration(handler, request); CorsConfiguration config = (globalConfig != null ? globalConfig.combine(handlerConfig) : handlerConfig); executionChain = getCorsHandlerExecutionChain(request, executionChain, config); } + return executionChain; } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractHandlerMethodMapping.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractHandlerMethodMapping.java index 3aa4f2d7b9..9e2a4d6165 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractHandlerMethodMapping.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractHandlerMethodMapping.java @@ -31,6 +31,9 @@ import java.util.concurrent.locks.ReentrantReadWriteLock; import javax.servlet.ServletException; import javax.servlet.http.HttpServletRequest; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; + import org.springframework.aop.support.AopUtils; import org.springframework.beans.factory.BeanFactoryUtils; import org.springframework.beans.factory.InitializingBean; @@ -165,6 +168,9 @@ public abstract class AbstractHandlerMethodMapping extends AbstractHandlerMap * @param method the method */ public void registerMapping(T mapping, Object handler, Method method) { + if (logger.isTraceEnabled()) { + logger.trace("Register \"" + mapping + "\" to " + method.toGenericString()); + } this.mappingRegistry.register(mapping, handler, method); } @@ -174,6 +180,9 @@ public abstract class AbstractHandlerMethodMapping extends AbstractHandlerMap * @param mapping the mapping to unregister */ public void unregisterMapping(T mapping) { + if (logger.isTraceEnabled()) { + logger.trace("Unregister mapping \"" + mapping); + } this.mappingRegistry.unregister(mapping); } @@ -185,7 +194,14 @@ public abstract class AbstractHandlerMethodMapping extends AbstractHandlerMap */ @Override public void afterPropertiesSet() { + initHandlerMethods(); + + if (logger.isDebugEnabled()) { + // Total includes detected mappings + explicit registrations via registerMapping.. + int total = this.getHandlerMethods().size(); + logger.debug("Detected " + total + " mappings in " + formatMappingName()); + } } /** @@ -195,9 +211,7 @@ public abstract class AbstractHandlerMethodMapping extends AbstractHandlerMap * @see #handlerMethodsInitialized(Map) */ protected void initHandlerMethods() { - if (logger.isDebugEnabled()) { - logger.debug("Looking for request mappings in application context: " + getApplicationContext()); - } + String[] beanNames = (this.detectHandlerMethodsInAncestorContexts ? BeanFactoryUtils.beanNamesForTypeIncludingAncestors(obtainApplicationContext(), Object.class) : obtainApplicationContext().getBeanNamesForType(Object.class)); @@ -210,8 +224,8 @@ public abstract class AbstractHandlerMethodMapping extends AbstractHandlerMap } catch (Throwable ex) { // An unresolvable bean type, probably from a lazy bean - let's ignore it. - if (logger.isDebugEnabled()) { - logger.debug("Could not resolve target class for bean with name '" + beanName + "'", ex); + if (logger.isTraceEnabled()) { + logger.trace("Could not resolve type for bean '" + beanName + "'", ex); } } if (beanType != null && isHandler(beanType)) { @@ -242,8 +256,8 @@ public abstract class AbstractHandlerMethodMapping extends AbstractHandlerMap userType.getName() + "]: " + method, ex); } }); - if (logger.isDebugEnabled()) { - logger.debug(methods.size() + " request handler methods found on " + userType + ": " + methods); + if (logger.isTraceEnabled()) { + logger.trace("Mapped " + methods.size() + " handler method(s) for " + userType + ": " + methods); } methods.forEach((method, mapping) -> { Method invocableMethod = AopUtils.selectInvocableMethod(method, userType); @@ -308,20 +322,9 @@ public abstract class AbstractHandlerMethodMapping extends AbstractHandlerMap @Override protected HandlerMethod getHandlerInternal(HttpServletRequest request) throws Exception { String lookupPath = getUrlPathHelper().getLookupPathForRequest(request); - if (logger.isDebugEnabled()) { - logger.debug("Looking up handler method for path " + lookupPath); - } this.mappingRegistry.acquireReadLock(); try { HandlerMethod handlerMethod = lookupHandlerMethod(lookupPath, request); - if (logger.isDebugEnabled()) { - if (handlerMethod != null) { - logger.debug("Returning handler method [" + handlerMethod + "]"); - } - else { - logger.debug("Did not find handler method for [" + lookupPath + "]"); - } - } return (handlerMethod != null ? handlerMethod.createWithResolvedBean() : null); } finally { @@ -353,11 +356,11 @@ public abstract class AbstractHandlerMethodMapping extends AbstractHandlerMap if (!matches.isEmpty()) { Comparator comparator = new MatchComparator(getMappingComparator(request)); matches.sort(comparator); - if (logger.isTraceEnabled()) { - logger.trace("Found " + matches.size() + " matching mapping(s) for [" + lookupPath + "] : " + matches); - } Match bestMatch = matches.get(0); if (matches.size() > 1) { + if (logger.isTraceEnabled()) { + logger.trace(matches.size() + " matching mapppings: " + matches); + } if (CorsUtils.isPreFlightRequest(request)) { return PREFLIGHT_AMBIGUOUS_MATCH; } @@ -365,8 +368,9 @@ public abstract class AbstractHandlerMethodMapping extends AbstractHandlerMap if (comparator.compare(bestMatch, secondBestMatch) == 0) { Method m1 = bestMatch.handlerMethod.getMethod(); Method m2 = secondBestMatch.handlerMethod.getMethod(); - throw new IllegalStateException("Ambiguous handler methods mapped for HTTP path '" + - request.getRequestURL() + "': {" + m1 + ", " + m2 + "}"); + String uri = request.getRequestURI(); + throw new IllegalStateException( + "Ambiguous handler methods mapped for '" + uri + "': {" + m1 + ", " + m2 + "}"); } } handleMatch(bestMatch.mapping, lookupPath, request); @@ -543,9 +547,6 @@ public abstract class AbstractHandlerMethodMapping extends AbstractHandlerMap HandlerMethod handlerMethod = createHandlerMethod(handler, method); assertUniqueMethodMapping(handlerMethod, mapping); - if (logger.isInfoEnabled()) { - logger.info("Mapped \"" + mapping + "\" onto " + handlerMethod); - } this.mappingLookup.put(mapping, handlerMethod); List directUrls = getDirectUrls(mapping); @@ -603,21 +604,10 @@ public abstract class AbstractHandlerMethodMapping extends AbstractHandlerMap } } - if (logger.isTraceEnabled()) { - logger.trace("Mapping name '" + name + "'"); - } - List newList = new ArrayList<>(oldList.size() + 1); newList.addAll(oldList); newList.add(handlerMethod); this.nameLookup.put(name, newList); - - if (newList.size() > 1) { - if (logger.isTraceEnabled()) { - logger.trace("Mapping name clash for handlerMethods " + newList + - ". Consider assigning explicit names."); - } - } } public void unregister(T mapping) { diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractUrlHandlerMapping.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractUrlHandlerMapping.java index 7732d9d6c5..0341d84fb2 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractUrlHandlerMapping.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/AbstractUrlHandlerMapping.java @@ -22,7 +22,6 @@ import java.util.Comparator; import java.util.LinkedHashMap; import java.util.List; import java.util.Map; - import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; @@ -142,12 +141,6 @@ public abstract class AbstractUrlHandlerMapping extends AbstractHandlerMapping i handler = buildPathExposingHandler(rawHandler, lookupPath, lookupPath, null); } } - if (handler != null && logger.isDebugEnabled()) { - logger.debug("Mapping [" + lookupPath + "] to " + handler); - } - else if (handler == null && logger.isTraceEnabled()) { - logger.trace("No handler mapping found for [" + lookupPath + "]"); - } return handler; } @@ -195,8 +188,8 @@ public abstract class AbstractUrlHandlerMapping extends AbstractHandlerMapping i Comparator patternComparator = getPathMatcher().getPatternComparator(urlPath); if (!matchingPatterns.isEmpty()) { matchingPatterns.sort(patternComparator); - if (logger.isDebugEnabled()) { - logger.debug("Matching patterns for request [" + urlPath + "] are " + matchingPatterns); + if (logger.isTraceEnabled() && matchingPatterns.size() > 1) { + logger.trace("Matching patterns " + matchingPatterns); } bestMatch = matchingPatterns.get(0); } @@ -229,8 +222,8 @@ public abstract class AbstractUrlHandlerMapping extends AbstractHandlerMapping i uriTemplateVariables.putAll(decodedVars); } } - if (logger.isDebugEnabled()) { - logger.debug("URI Template variables for request [" + urlPath + "] are " + uriTemplateVariables); + if (logger.isTraceEnabled() && uriTemplateVariables.size() > 0) { + logger.trace("URI variables " + uriTemplateVariables); } return buildPathExposingHandler(handler, bestMatch, pathWithinMapping, uriTemplateVariables); } @@ -356,28 +349,28 @@ public abstract class AbstractUrlHandlerMapping extends AbstractHandlerMapping i } else { if (urlPath.equals("/")) { - if (logger.isInfoEnabled()) { - logger.info("Root mapping to " + getHandlerDescription(handler)); + if (logger.isTraceEnabled()) { + logger.trace("Root mapping to " + getHandlerDescription(handler)); } setRootHandler(resolvedHandler); } else if (urlPath.equals("/*")) { - if (logger.isInfoEnabled()) { - logger.info("Default mapping to " + getHandlerDescription(handler)); + if (logger.isTraceEnabled()) { + logger.trace("Default mapping to " + getHandlerDescription(handler)); } setDefaultHandler(resolvedHandler); } else { this.handlerMap.put(urlPath, resolvedHandler); - if (logger.isInfoEnabled()) { - logger.info("Mapped URL path [" + urlPath + "] onto " + getHandlerDescription(handler)); + if (logger.isTraceEnabled()) { + logger.trace("Mapped URL path [" + urlPath + "] onto " + getHandlerDescription(handler)); } } } } private String getHandlerDescription(Object handler) { - return "handler " + (handler instanceof String ? "'" + handler + "'" : "of type [" + handler.getClass() + "]"); + return (handler instanceof String ? "'" + handler + "'" : handler.toString()); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/SimpleMappingExceptionResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/SimpleMappingExceptionResolver.java index ae09e06d17..c714c4a775 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/SimpleMappingExceptionResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/SimpleMappingExceptionResolver.java @@ -226,8 +226,7 @@ public class SimpleMappingExceptionResolver extends AbstractHandlerExceptionReso // Return default error view else, if defined. if (viewName == null && this.defaultErrorView != null) { if (logger.isDebugEnabled()) { - logger.debug("Resolving to default view '" + this.defaultErrorView + "' for exception of type [" + - ex.getClass().getName() + "]"); + logger.debug("Resolving to default view '" + this.defaultErrorView + "'"); } viewName = this.defaultErrorView; } @@ -257,8 +256,7 @@ public class SimpleMappingExceptionResolver extends AbstractHandlerExceptionReso } } if (viewName != null && logger.isDebugEnabled()) { - logger.debug("Resolving to view '" + viewName + "' for exception of type [" + ex.getClass().getName() + - "], based on exception mapping [" + dominantMapping + "]"); + logger.debug("Resolving to view '" + viewName + "' based on mapping [" + dominantMapping + "]"); } return viewName; } @@ -318,7 +316,7 @@ public class SimpleMappingExceptionResolver extends AbstractHandlerExceptionReso protected void applyStatusCodeIfPossible(HttpServletRequest request, HttpServletResponse response, int statusCode) { if (!WebUtils.isIncludeRequest(request)) { if (logger.isDebugEnabled()) { - logger.debug("Applying HTTP status code " + statusCode); + logger.debug("Applying HTTP status " + statusCode); } response.setStatus(statusCode); request.setAttribute(WebUtils.ERROR_STATUS_CODE_ATTRIBUTE, statusCode); @@ -349,9 +347,6 @@ public class SimpleMappingExceptionResolver extends AbstractHandlerExceptionReso protected ModelAndView getModelAndView(String viewName, Exception ex) { ModelAndView mv = new ModelAndView(viewName); if (this.exceptionAttribute != null) { - if (logger.isDebugEnabled()) { - logger.debug("Exposing Exception as model attribute '" + this.exceptionAttribute + "'"); - } mv.addObject(this.exceptionAttribute, ex); } return mv; diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/SimpleUrlHandlerMapping.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/SimpleUrlHandlerMapping.java index 02b69ed6a0..5013ce91ae 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/SimpleUrlHandlerMapping.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/handler/SimpleUrlHandlerMapping.java @@ -16,9 +16,12 @@ package org.springframework.web.servlet.handler; +import java.util.ArrayList; import java.util.LinkedHashMap; +import java.util.List; import java.util.Map; import java.util.Properties; +import java.util.Set; import org.springframework.beans.BeansException; import org.springframework.util.CollectionUtils; @@ -111,7 +114,7 @@ public class SimpleUrlHandlerMapping extends AbstractUrlHandlerMapping { */ protected void registerHandlers(Map urlMap) throws BeansException { if (urlMap.isEmpty()) { - logger.warn("Neither 'urlMap' nor 'mappings' set on SimpleUrlHandlerMapping"); + logger.warn("Neither 'urlMap' nor 'mappings' set, " + formatMappingName()); } else { urlMap.forEach((url, handler) -> { @@ -125,6 +128,17 @@ public class SimpleUrlHandlerMapping extends AbstractUrlHandlerMapping { } registerHandler(url, handler); }); + if (logger.isDebugEnabled()) { + List patterns = new ArrayList<>(); + if (getRootHandler() != null) { + patterns.add("/"); + } + if (getDefaultHandler() != null) { + patterns.add("/**"); + } + patterns.addAll(getHandlerMap().keySet()); + logger.debug("Patterns " + patterns + " in " + formatMappingName()); + } } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/i18n/CookieLocaleResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/i18n/CookieLocaleResolver.java index e119d6791f..00af82fea1 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/i18n/CookieLocaleResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/i18n/CookieLocaleResolver.java @@ -205,20 +205,20 @@ public class CookieLocaleResolver extends CookieGenerator implements LocaleConte } } catch (IllegalArgumentException ex) { + String reason = "Ignoring invalid locale cookie '" + + cookieName + ":" + value + "' due to: " + ex.getMessage(); if (request.getAttribute(WebUtils.ERROR_EXCEPTION_ATTRIBUTE) != null) { // Error dispatch: ignore locale/timezone parse exceptions if (logger.isDebugEnabled()) { - logger.debug("Ignoring invalid locale cookie '" + cookieName + - "' with value [" + value + "] due to error dispatch: " + ex.getMessage()); + logger.debug(reason); } } else { - throw new IllegalStateException("Invalid locale cookie '" + cookieName + - "' with value [" + value + "]: " + ex.getMessage()); + throw new IllegalStateException(reason); } } - if (logger.isDebugEnabled()) { - logger.debug("Parsed cookie value [" + cookie.getValue() + "] into locale '" + locale + + if (logger.isTraceEnabled()) { + logger.trace("Parsed cookie value [" + cookie.getValue() + "] into locale '" + locale + "'" + (timeZone != null ? " and time zone '" + timeZone.getID() + "'" : "")); } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/AbstractUrlViewController.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/AbstractUrlViewController.java index 14b1e82caa..45771e5661 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/AbstractUrlViewController.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/AbstractUrlViewController.java @@ -100,10 +100,9 @@ public abstract class AbstractUrlViewController extends AbstractController { */ @Override protected ModelAndView handleRequestInternal(HttpServletRequest request, HttpServletResponse response) { - String lookupPath = getUrlPathHelper().getLookupPathForRequest(request); String viewName = getViewNameForRequest(request); - if (logger.isDebugEnabled()) { - logger.debug("Returning view name '" + viewName + "' for lookup path [" + lookupPath + "]"); + if (logger.isTraceEnabled()) { + logger.trace("Returning view name '" + viewName + "'"); } return new ModelAndView(viewName, RequestContextUtils.getInputFlashMap(request)); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/ParameterizableViewController.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/ParameterizableViewController.java index cb8bf8d4b3..8a8ea1903e 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/ParameterizableViewController.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/ParameterizableViewController.java @@ -67,7 +67,16 @@ public class ParameterizableViewController extends AbstractController { */ @Nullable public String getViewName() { - return (this.view instanceof String ? (String) this.view : null); + if (this.view instanceof String) { + String viewName = (String) this.view; + if (getStatusCode() != null && getStatusCode().is3xxRedirection()) { + return viewName.startsWith("redirect:") ? viewName : "redirect:" + viewName; + } + else { + return viewName; + } + } + return null; } /** @@ -148,27 +157,45 @@ public class ParameterizableViewController extends AbstractController { if (getStatusCode() != null) { if (getStatusCode().is3xxRedirection()) { request.setAttribute(View.RESPONSE_STATUS_ATTRIBUTE, getStatusCode()); - viewName = (viewName != null && !viewName.startsWith("redirect:") ? "redirect:" + viewName : viewName); } else { response.setStatus(getStatusCode().value()); - if (isStatusOnly() || (getStatusCode().equals(HttpStatus.NO_CONTENT) && getViewName() == null)) { + if (getStatusCode().equals(HttpStatus.NO_CONTENT) && viewName == null) { return null; } } } + if (isStatusOnly()) { + return null; + } + ModelAndView modelAndView = new ModelAndView(); modelAndView.addAllObjects(RequestContextUtils.getInputFlashMap(request)); - - if (getViewName() != null) { + if (viewName != null) { modelAndView.setViewName(viewName); } else { modelAndView.setView(getView()); } - - return (isStatusOnly() ? null : modelAndView); + return modelAndView; } + @Override + public String toString() { + return "ParameterizableViewController [" + formatStatusAndView() + "]"; + } + + private String formatStatusAndView() { + StringBuilder sb = new StringBuilder(); + if (this.statusCode != null) { + sb.append("status=").append(this.statusCode); + } + if (this.view != null) { + sb.append(sb.length() != 0 ? ", " : ""); + String viewName = getViewName(); + sb.append("view=").append(viewName != null ? "\"" + viewName + "\"" : this.view); + } + return sb.toString(); + } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/ServletForwardingController.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/ServletForwardingController.java index ef2933cdb2..e0aaa8219b 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/ServletForwardingController.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/ServletForwardingController.java @@ -132,15 +132,15 @@ public class ServletForwardingController extends AbstractController implements B // If already included, include again, else forward. if (useInclude(request, response)) { rd.include(request, response); - if (logger.isDebugEnabled()) { - logger.debug("Included servlet [" + this.servletName + + if (logger.isTraceEnabled()) { + logger.trace("Included servlet [" + this.servletName + "] in ServletForwardingController '" + this.beanName + "'"); } } else { rd.forward(request, response); - if (logger.isDebugEnabled()) { - logger.debug("Forwarded to servlet [" + this.servletName + + if (logger.isTraceEnabled()) { + logger.trace("Forwarded to servlet [" + this.servletName + "] in ServletForwardingController '" + this.beanName + "'"); } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/WebContentInterceptor.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/WebContentInterceptor.java index d599ec52dc..b88e2b44ff 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/WebContentInterceptor.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/WebContentInterceptor.java @@ -170,27 +170,24 @@ public class WebContentInterceptor extends WebContentGenerator implements Handle checkRequest(request); String lookupPath = this.urlPathHelper.getLookupPathForRequest(request); - if (logger.isDebugEnabled()) { - logger.debug("Looking up cache seconds for [" + lookupPath + "]"); - } CacheControl cacheControl = lookupCacheControl(lookupPath); Integer cacheSeconds = lookupCacheSeconds(lookupPath); if (cacheControl != null) { - if (logger.isDebugEnabled()) { - logger.debug("Applying CacheControl to [" + lookupPath + "]"); + if (logger.isTraceEnabled()) { + logger.trace("Applying " + cacheControl); } applyCacheControl(response, cacheControl); } else if (cacheSeconds != null) { - if (logger.isDebugEnabled()) { - logger.debug("Applying CacheControl to [" + lookupPath + "]"); + if (logger.isTraceEnabled()) { + logger.trace("Applying cacheSeconds " + cacheSeconds); } applyCacheSeconds(response, cacheSeconds); } else { - if (logger.isDebugEnabled()) { - logger.debug("Applying default cache seconds to [" + lookupPath + "]"); + if (logger.isTraceEnabled()) { + logger.trace("Applying default cacheSeconds"); } prepareResponse(response); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/annotation/ResponseStatusExceptionResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/annotation/ResponseStatusExceptionResolver.java index 542795e616..67161464b1 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/annotation/ResponseStatusExceptionResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/annotation/ResponseStatusExceptionResolver.java @@ -86,7 +86,7 @@ public class ResponseStatusExceptionResolver extends AbstractHandlerExceptionRes } } catch (Exception resolveEx) { - logger.warn("ResponseStatus handling resulted in exception", resolveEx); + logger.warn("Failure while trying to resolve exception [" + ex.getClass().getName() + "]", resolveEx); } return null; } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/AbstractMessageConverterMethodArgumentResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/AbstractMessageConverterMethodArgumentResolver.java index 9081bae65b..f73229e4fc 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/AbstractMessageConverterMethodArgumentResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/AbstractMessageConverterMethodArgumentResolver.java @@ -197,9 +197,6 @@ public abstract class AbstractMessageConverterMethodArgumentResolver implements (converter instanceof GenericHttpMessageConverter ? (GenericHttpMessageConverter) converter : null); if (genericConverter != null ? genericConverter.canRead(targetType, contextClass, contentType) : (targetClass != null && converter.canRead(targetClass, contentType))) { - if (logger.isDebugEnabled()) { - logger.debug("Read [" + targetType + "] as \"" + contentType + "\" with [" + converter + "]"); - } if (message.hasBody()) { HttpInputMessage msgToUse = getAdvice().beforeBodyRead(message, parameter, targetType, converterType); @@ -226,6 +223,11 @@ public abstract class AbstractMessageConverterMethodArgumentResolver implements throw new HttpMediaTypeNotSupportedException(contentType, this.allSupportedMediaTypes); } + if (logger.isDebugEnabled()) { + logger.debug("Read \"" + contentType + "\" to " + + "[" + (body instanceof String ? "\"" + body + "\"" : body) + "]"); + } + return body; } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/AbstractMessageConverterMethodProcessor.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/AbstractMessageConverterMethodProcessor.java index 913ff767d1..35f71abb70 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/AbstractMessageConverterMethodProcessor.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/AbstractMessageConverterMethodProcessor.java @@ -177,18 +177,18 @@ public abstract class AbstractMessageConverterMethodProcessor extends AbstractMe ServletServerHttpRequest inputMessage, ServletServerHttpResponse outputMessage) throws IOException, HttpMediaTypeNotAcceptableException, HttpMessageNotWritableException { - Object outputValue; + Object body; Class valueType; Type declaredType; if (value instanceof CharSequence) { - outputValue = value.toString(); + body = value.toString(); valueType = String.class; declaredType = String.class; } else { - outputValue = value; - valueType = getReturnValueType(outputValue, returnType); + body = value; + valueType = getReturnValueType(body, returnType); declaredType = getGenericType(returnType); } @@ -199,8 +199,8 @@ public abstract class AbstractMessageConverterMethodProcessor extends AbstractMe try { List httpRanges = inputMessage.getHeaders().getRange(); outputMessage.getServletResponse().setStatus(HttpStatus.PARTIAL_CONTENT.value()); - outputValue = HttpRange.toResourceRegions(httpRanges, resource); - valueType = outputValue.getClass(); + body = HttpRange.toResourceRegions(httpRanges, resource); + valueType = body.getClass(); declaredType = RESOURCE_REGION_LIST_TYPE; } catch (IllegalArgumentException ex) { @@ -222,7 +222,7 @@ public abstract class AbstractMessageConverterMethodProcessor extends AbstractMe List requestedMediaTypes = getAcceptableMediaTypes(request); List producibleMediaTypes = getProducibleMediaTypes(request, valueType, declaredType); - if (outputValue != null && producibleMediaTypes.isEmpty()) { + if (body != null && producibleMediaTypes.isEmpty()) { throw new HttpMessageNotWritableException( "No converter found for return value of type: " + valueType); } @@ -235,7 +235,7 @@ public abstract class AbstractMessageConverterMethodProcessor extends AbstractMe } } if (mediaTypesToUse.isEmpty()) { - if (outputValue != null) { + if (body != null) { throw new HttpMediaTypeNotAcceptableException(producibleMediaTypes); } return; @@ -263,20 +263,20 @@ public abstract class AbstractMessageConverterMethodProcessor extends AbstractMe if (genericConverter != null ? ((GenericHttpMessageConverter) converter).canWrite(declaredType, valueType, selectedMediaType) : converter.canWrite(valueType, selectedMediaType)) { - outputValue = getAdvice().beforeBodyWrite(outputValue, returnType, selectedMediaType, + body = getAdvice().beforeBodyWrite(body, returnType, selectedMediaType, (Class>) converter.getClass(), inputMessage, outputMessage); - if (outputValue != null) { + if (body != null) { addContentDispositionHeader(inputMessage, outputMessage); if (genericConverter != null) { - genericConverter.write(outputValue, declaredType, selectedMediaType, outputMessage); + genericConverter.write(body, declaredType, selectedMediaType, outputMessage); } else { - ((HttpMessageConverter) converter).write(outputValue, selectedMediaType, outputMessage); + ((HttpMessageConverter) converter).write(body, selectedMediaType, outputMessage); } if (logger.isDebugEnabled()) { - logger.debug("Written [" + outputValue + "] as \"" + selectedMediaType + - "\" using [" + converter + "]"); + logger.debug("Written \"" + selectedMediaType + "\" from " + + "[" + (body instanceof CharSequence ? "\"" + body + "\"" : body) + "]"); } } return; @@ -284,7 +284,7 @@ public abstract class AbstractMessageConverterMethodProcessor extends AbstractMe } } - if (outputValue != null) { + if (body != null) { throw new HttpMediaTypeNotAcceptableException(this.allSupportedMediaTypes); } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ExceptionHandlerExceptionResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ExceptionHandlerExceptionResolver.java index b7da900e02..7f49e3635a 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ExceptionHandlerExceptionResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ExceptionHandlerExceptionResolver.java @@ -269,9 +269,6 @@ public class ExceptionHandlerExceptionResolver extends AbstractHandlerMethodExce if (getApplicationContext() == null) { return; } - if (logger.isDebugEnabled()) { - logger.debug("Looking for exception mappings: " + getApplicationContext()); - } List adviceBeans = ControllerAdviceBean.findAnnotatedBeans(getApplicationContext()); AnnotationAwareOrderComparator.sort(adviceBeans); @@ -284,15 +281,21 @@ public class ExceptionHandlerExceptionResolver extends AbstractHandlerMethodExce ExceptionHandlerMethodResolver resolver = new ExceptionHandlerMethodResolver(beanType); if (resolver.hasExceptionMappings()) { this.exceptionHandlerAdviceCache.put(adviceBean, resolver); - if (logger.isInfoEnabled()) { - logger.info("Detected @ExceptionHandler methods in " + adviceBean); - } } if (ResponseBodyAdvice.class.isAssignableFrom(beanType)) { this.responseBodyAdvice.add(adviceBean); - if (logger.isInfoEnabled()) { - logger.info("Detected ResponseBodyAdvice implementation in " + adviceBean); - } + } + } + + if (logger.isDebugEnabled()) { + int handlerSize = this.exceptionHandlerAdviceCache.size(); + int adviceSize = this.responseBodyAdvice.size(); + if (handlerSize == 0 && adviceSize == 0) { + logger.debug("ControllerAdvice beans: none"); + } + else { + logger.debug("ControllerAdvice beans: " + + handlerSize + " @ExceptionHandler, " + adviceSize + " ResponseBodyAdvice"); } } } @@ -392,7 +395,7 @@ public class ExceptionHandlerExceptionResolver extends AbstractHandlerMethodExce try { if (logger.isDebugEnabled()) { - logger.debug("Invoking @ExceptionHandler method: " + exceptionHandlerMethod); + logger.debug("Using @ExceptionHandler " + exceptionHandlerMethod); } Throwable cause = exception.getCause(); if (cause != null) { @@ -408,7 +411,7 @@ public class ExceptionHandlerExceptionResolver extends AbstractHandlerMethodExce // Any other than the original exception is unintended here, // probably an accident (e.g. failed assertion or the like). if (invocationEx != exception && logger.isWarnEnabled()) { - logger.warn("Failed to invoke @ExceptionHandler method: " + exceptionHandlerMethod, invocationEx); + logger.warn("Failure in @ExceptionHandler " + exceptionHandlerMethod, invocationEx); } // Continue with default processing of the original exception... return null; diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ExtendedServletRequestDataBinder.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ExtendedServletRequestDataBinder.java index 3d1e707074..03aaa10745 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ExtendedServletRequestDataBinder.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ExtendedServletRequestDataBinder.java @@ -68,7 +68,7 @@ public class ExtendedServletRequestDataBinder extends ServletRequestDataBinder { if (mpvs.contains(name)) { if (logger.isWarnEnabled()) { logger.warn("Skipping URI variable '" + name + - "' since the request contains a bind value with the same name."); + "' because request contains bind value with same name."); } } else { diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/MvcUriComponentsBuilder.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/MvcUriComponentsBuilder.java index 253905b5cb..e7eb9778b5 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/MvcUriComponentsBuilder.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/MvcUriComponentsBuilder.java @@ -583,8 +583,8 @@ public class MvcUriComponentsBuilder { if (ObjectUtils.isEmpty(paths) || StringUtils.isEmpty(paths[0])) { return "/"; } - if (paths.length > 1 && logger.isWarnEnabled()) { - logger.warn("Multiple paths on controller " + controllerType.getName() + ", using first one"); + if (paths.length > 1 && logger.isTraceEnabled()) { + logger.trace("Using first of multiple paths on " + controllerType.getName()); } return paths[0]; } @@ -599,8 +599,8 @@ public class MvcUriComponentsBuilder { if (ObjectUtils.isEmpty(paths) || StringUtils.isEmpty(paths[0])) { return "/"; } - if (paths.length > 1 && logger.isWarnEnabled()) { - logger.warn("Multiple paths on method " + method.toGenericString() + ", using first one"); + if (paths.length > 1 && logger.isTraceEnabled()) { + logger.trace("Using first of multiple paths on " + method.toGenericString()); } return paths[0]; } @@ -628,10 +628,6 @@ public class MvcUriComponentsBuilder { private static UriComponents applyContributors(UriComponentsBuilder builder, Method method, Object... args) { CompositeUriComponentsContributor contributor = getUriComponentsContributor(); - if (contributor == null) { - logger.trace("Using default CompositeUriComponentsContributor"); - contributor = defaultUriComponentsContributor; - } int paramCount = method.getParameterCount(); int argCount = args.length; @@ -652,35 +648,29 @@ public class MvcUriComponentsBuilder { uriVars.getOrDefault(name, UriComponents.UriTemplateVariables.SKIP_VALUE)); } - @Nullable private static CompositeUriComponentsContributor getUriComponentsContributor() { WebApplicationContext wac = getWebApplicationContext(); - if (wac == null) { - return null; - } - try { - return wac.getBean(MVC_URI_COMPONENTS_CONTRIBUTOR_BEAN_NAME, CompositeUriComponentsContributor.class); - } - catch (NoSuchBeanDefinitionException ex) { - if (logger.isTraceEnabled()) { - logger.trace("No CompositeUriComponentsContributor"); + if (wac != null) { + try { + return wac.getBean(MVC_URI_COMPONENTS_CONTRIBUTOR_BEAN_NAME, CompositeUriComponentsContributor.class); + } + catch (NoSuchBeanDefinitionException ex) { + // Ignore } - return null; } + return defaultUriComponentsContributor; } @Nullable private static WebApplicationContext getWebApplicationContext() { RequestAttributes requestAttributes = RequestContextHolder.getRequestAttributes(); if (requestAttributes == null) { - logger.trace("No request bound to the current thread: not in a DispatcherServlet request?"); return null; } HttpServletRequest request = ((ServletRequestAttributes) requestAttributes).getRequest(); String attributeName = DispatcherServlet.WEB_APPLICATION_CONTEXT_ATTRIBUTE; WebApplicationContext wac = (WebApplicationContext) request.getAttribute(attributeName); if (wac == null) { - logger.trace("No WebApplicationContext found: not in a DispatcherServlet request?"); return null; } return wac; @@ -800,8 +790,7 @@ public class MvcUriComponentsBuilder { proxy = objenesis.newInstance(proxyClass, enhancer.getUseCache()); } catch (ObjenesisException ex) { - logger.debug("Unable to instantiate controller proxy using Objenesis, " + - "falling back to regular construction", ex); + logger.debug("Failed to create controller proxy, falling back on default constructor", ex); } } @@ -810,8 +799,8 @@ public class MvcUriComponentsBuilder { proxy = ReflectionUtils.accessibleConstructor(proxyClass).newInstance(); } catch (Throwable ex) { - throw new IllegalStateException("Unable to instantiate controller proxy using Objenesis, " + - "and regular controller instantiation via default constructor fails as well", ex); + throw new IllegalStateException( + "Failed to create controller proxy or use default constructor", ex); } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ReactiveTypeHandler.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ReactiveTypeHandler.java index 0a6a2fd15c..081f3df6bf 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ReactiveTypeHandler.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ReactiveTypeHandler.java @@ -211,12 +211,12 @@ class ReactiveTypeHandler { @Override public final void onSubscribe(Subscription subscription) { this.subscription = subscription; - if (logger.isDebugEnabled()) { - logger.debug("Subscribed to Publisher for " + this.emitter); + if (logger.isTraceEnabled()) { + logger.trace("Subscribed to Publisher for " + this.emitter); } this.emitter.onTimeout(() -> { if (logger.isDebugEnabled()) { - logger.debug("Connection timed out for " + this.emitter); + logger.debug("Connection timeout for " + this.emitter); } terminate(); this.emitter.complete(); @@ -304,7 +304,7 @@ class ReactiveTypeHandler { } else { if (logger.isDebugEnabled()) { - logger.debug("Publishing completed for " + this.emitter); + logger.debug("Publisher completed for " + this.emitter); } this.emitter.complete(); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/RequestMappingHandlerAdapter.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/RequestMappingHandlerAdapter.java index 0945146f3d..e9ff094367 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/RequestMappingHandlerAdapter.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/RequestMappingHandlerAdapter.java @@ -570,9 +570,6 @@ public class RequestMappingHandlerAdapter extends AbstractHandlerMethodAdapter if (getApplicationContext() == null) { return; } - if (logger.isInfoEnabled()) { - logger.info("Looking for @ControllerAdvice: " + getApplicationContext()); - } List adviceBeans = ControllerAdviceBean.findAnnotatedBeans(getApplicationContext()); AnnotationAwareOrderComparator.sort(adviceBeans); @@ -587,34 +584,45 @@ public class RequestMappingHandlerAdapter extends AbstractHandlerMethodAdapter Set attrMethods = MethodIntrospector.selectMethods(beanType, MODEL_ATTRIBUTE_METHODS); if (!attrMethods.isEmpty()) { this.modelAttributeAdviceCache.put(adviceBean, attrMethods); - if (logger.isInfoEnabled()) { - logger.info("Detected @ModelAttribute methods in " + adviceBean); - } } Set binderMethods = MethodIntrospector.selectMethods(beanType, INIT_BINDER_METHODS); if (!binderMethods.isEmpty()) { this.initBinderAdviceCache.put(adviceBean, binderMethods); - if (logger.isInfoEnabled()) { - logger.info("Detected @InitBinder methods in " + adviceBean); - } } if (RequestBodyAdvice.class.isAssignableFrom(beanType)) { requestResponseBodyAdviceBeans.add(adviceBean); - if (logger.isInfoEnabled()) { - logger.info("Detected RequestBodyAdvice bean in " + adviceBean); - } } if (ResponseBodyAdvice.class.isAssignableFrom(beanType)) { requestResponseBodyAdviceBeans.add(adviceBean); - if (logger.isInfoEnabled()) { - logger.info("Detected ResponseBodyAdvice bean in " + adviceBean); - } } } if (!requestResponseBodyAdviceBeans.isEmpty()) { this.requestResponseBodyAdvice.addAll(0, requestResponseBodyAdviceBeans); } + + if (logger.isDebugEnabled()) { + int modelSize = this.modelAttributeAdviceCache.size(); + int binderSize = this.initBinderAdviceCache.size(); + int reqCount = getBodyAdviceCount(RequestBodyAdvice.class); + int resCount = getBodyAdviceCount(ResponseBodyAdvice.class); + if (modelSize == 0 && binderSize == 0 && reqCount == 0 && resCount == 0) { + logger.debug("ControllerAdvice beans: none"); + } + else { + logger.debug("ControllerAdvice beans: " + modelSize + " @ModelAttribute, " + binderSize + + " @InitBinder, " + reqCount + " RequestBodyAdvice, " + resCount + ", ResponseBodyAdvice"); + } + } + } + + // Count all advice, including explicit registrations.. + + private int getBodyAdviceCount(Class adviceType) { + List advice = this.requestResponseBodyAdvice; + return RequestBodyAdvice.class.isAssignableFrom(adviceType) ? + RequestResponseBodyAdviceChain.getAdviceByType(advice, RequestBodyAdvice.class).size() : + RequestResponseBodyAdviceChain.getAdviceByType(advice, ResponseBodyAdvice.class).size(); } /** @@ -869,7 +877,8 @@ public class RequestMappingHandlerAdapter extends AbstractHandlerMethodAdapter mavContainer = (ModelAndViewContainer) asyncManager.getConcurrentResultContext()[0]; asyncManager.clearConcurrentResult(); if (logger.isDebugEnabled()) { - logger.debug("Found concurrent result value [" + result + "]"); + logger.debug("Resume with async result [" + + (result instanceof CharSequence ? "\"" + result + "\"" : result) + "]"); } invocableMethod = invocableMethod.wrapConcurrentResult(result); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/RequestResponseBodyAdviceChain.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/RequestResponseBodyAdviceChain.java index 8958484c52..0e373eafe0 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/RequestResponseBodyAdviceChain.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/RequestResponseBodyAdviceChain.java @@ -21,6 +21,7 @@ import java.lang.reflect.Type; import java.util.ArrayList; import java.util.Collections; import java.util.List; +import java.util.stream.Collectors; import org.springframework.core.MethodParameter; import org.springframework.http.HttpInputMessage; @@ -52,20 +53,24 @@ class RequestResponseBodyAdviceChain implements RequestBodyAdvice, ResponseBodyA * {@code ControllerAdviceBean} or {@code RequestBodyAdvice}. */ public RequestResponseBodyAdviceChain(@Nullable List requestResponseBodyAdvice) { + this.requestBodyAdvice.addAll(getAdviceByType(requestResponseBodyAdvice, RequestBodyAdvice.class)); + this.responseBodyAdvice.addAll(getAdviceByType(requestResponseBodyAdvice, ResponseBodyAdvice.class)); + } + + @SuppressWarnings("unchecked") + static List getAdviceByType(@Nullable List requestResponseBodyAdvice, Class adviceType) { if (requestResponseBodyAdvice != null) { + List result = new ArrayList<>(); for (Object advice : requestResponseBodyAdvice) { Class beanType = (advice instanceof ControllerAdviceBean ? ((ControllerAdviceBean) advice).getBeanType() : advice.getClass()); - if (beanType != null) { - if (RequestBodyAdvice.class.isAssignableFrom(beanType)) { - this.requestBodyAdvice.add(advice); - } - else if (ResponseBodyAdvice.class.isAssignableFrom(beanType)) { - this.responseBodyAdvice.add(advice); - } + if (beanType != null && adviceType.isAssignableFrom(beanType)) { + result.add((T) advice); } } + return result; } + return Collections.emptyList(); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ResponseBodyEmitterReturnValueHandler.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ResponseBodyEmitterReturnValueHandler.java index 0f96b85169..7729eb504c 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ResponseBodyEmitterReturnValueHandler.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ResponseBodyEmitterReturnValueHandler.java @@ -193,7 +193,9 @@ public class ResponseBodyEmitterReturnValueHandler implements HandlerMethodRetur @SuppressWarnings("unchecked") private void sendInternal(T data, @Nullable MediaType mediaType) throws IOException { if (logger.isTraceEnabled()) { - logger.trace("Writing [" + data + "]"); + String format = mediaType != null ? "\"" + mediaType + "\" from " : ""; + logger.trace("Writing " + format + "[" + + (data instanceof CharSequence ? "\"" + data + "\"" : data) + "]"); } for (HttpMessageConverter converter : ResponseBodyEmitterReturnValueHandler.this.messageConverters) { if (converter.canWrite(data.getClass(), mediaType)) { diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ResponseEntityExceptionHandler.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ResponseEntityExceptionHandler.java index 41c8d4aa3f..e8b1c9a19a 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ResponseEntityExceptionHandler.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ResponseEntityExceptionHandler.java @@ -18,7 +18,6 @@ package org.springframework.web.servlet.mvc.method.annotation; import java.util.List; import java.util.Set; -import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; import org.apache.commons.logging.Log; @@ -434,11 +433,10 @@ public abstract class ResponseEntityExceptionHandler { if (webRequest instanceof ServletWebRequest) { ServletWebRequest servletWebRequest = (ServletWebRequest) webRequest; - HttpServletRequest request = servletWebRequest.getRequest(); HttpServletResponse response = servletWebRequest.getResponse(); if (response != null && response.isCommitted()) { - if (logger.isDebugEnabled()) { - logger.debug("Async timeout for " + request.getMethod() + " [" + request.getRequestURI() + "]"); + if (logger.isWarnEnabled()) { + logger.warn("Async request timed out"); } return null; } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ServletInvocableHandlerMethod.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ServletInvocableHandlerMethod.java index dc1206f438..0b19fffd61 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ServletInvocableHandlerMethod.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/method/annotation/ServletInvocableHandlerMethod.java @@ -121,7 +121,7 @@ public class ServletInvocableHandlerMethod extends InvocableHandlerMethod { } catch (Exception ex) { if (logger.isTraceEnabled()) { - logger.trace(getReturnValueHandlingErrorMessage("Error handling return value", returnValue), ex); + logger.trace(formatErrorForReturnValue("Error handling return value", returnValue), ex); } throw ex; } @@ -160,7 +160,7 @@ public class ServletInvocableHandlerMethod extends InvocableHandlerMethod { return webRequest.isNotModified(); } - private String getReturnValueHandlingErrorMessage(String message, @Nullable Object returnValue) { + private String formatErrorForReturnValue(String message, @Nullable Object returnValue) { StringBuilder sb = new StringBuilder(message); if (returnValue != null) { sb.append(" [type=").append(returnValue.getClass().getName()).append("]"); diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/support/DefaultHandlerExceptionResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/support/DefaultHandlerExceptionResolver.java index 652ddbeb96..ac5945b8d3 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/support/DefaultHandlerExceptionResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/mvc/support/DefaultHandlerExceptionResolver.java @@ -227,13 +227,15 @@ public class DefaultHandlerExceptionResolver extends AbstractHandlerExceptionRes return handleAsyncRequestTimeoutException( (AsyncRequestTimeoutException) ex, request, response, handler); } - } - catch (Exception handlerException) { - if (logger.isWarnEnabled()) { - logger.warn("Handling of [" + ex.getClass().getName() + "] resulted in exception", handlerException); + else { + return null; } + + } + catch (Exception handlerEx) { + logger.warn("Failure while trying to resolve exception [" + ex.getClass().getName() + "]", handlerEx); + return null; } - return null; } /** @@ -541,8 +543,8 @@ public class DefaultHandlerExceptionResolver extends AbstractHandlerExceptionRes if (!response.isCommitted()) { response.sendError(HttpServletResponse.SC_SERVICE_UNAVAILABLE); } - else if (logger.isDebugEnabled()) { - logger.debug("Async timeout for " + request.getMethod() + " [" + request.getRequestURI() + "]"); + else if (logger.isWarnEnabled()) { + logger.warn("Async request timed out"); } return new ModelAndView(); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/AbstractResourceResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/AbstractResourceResolver.java index 1678166120..92b30c0f4b 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/AbstractResourceResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/AbstractResourceResolver.java @@ -42,9 +42,6 @@ public abstract class AbstractResourceResolver implements ResourceResolver { public Resource resolveResource(@Nullable HttpServletRequest request, String requestPath, List locations, ResourceResolverChain chain) { - if (logger.isTraceEnabled()) { - logger.trace("Resolving resource for request path \"" + requestPath + "\""); - } return resolveResourceInternal(request, requestPath, locations, chain); } @@ -53,10 +50,6 @@ public abstract class AbstractResourceResolver implements ResourceResolver { public String resolveUrlPath(String resourceUrlPath, List locations, ResourceResolverChain chain) { - if (logger.isTraceEnabled()) { - logger.trace("Resolving public URL for resource path \"" + resourceUrlPath + "\""); - } - return resolveUrlPathInternal(resourceUrlPath, locations, chain); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/AppCacheManifestTransformer.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/AppCacheManifestTransformer.java index 2777e13639..05f18d86a6 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/AppCacheManifestTransformer.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/AppCacheManifestTransformer.java @@ -109,15 +109,11 @@ public class AppCacheManifestTransformer extends ResourceTransformerSupport { if (!content.startsWith(MANIFEST_HEADER)) { if (logger.isTraceEnabled()) { - logger.trace("Manifest should start with 'CACHE MANIFEST', skip: " + resource); + logger.trace("Skipping " + resource + ": Manifest does not start with 'CACHE MANIFEST'"); } return resource; } - if (logger.isTraceEnabled()) { - logger.trace("Transforming resource: " + resource); - } - @SuppressWarnings("resource") Scanner scanner = new Scanner(content); LineInfo previous = null; @@ -152,15 +148,6 @@ public class AppCacheManifestTransformer extends ResourceTransformerSupport { String absolutePath = toAbsolutePath(path, request); String newPath = resolveUrlPath(absolutePath, request, resource, transformerChain); - if (logger.isTraceEnabled()) { - if (newPath != null && !newPath.equals(path)) { - logger.trace("Link modified: " + path + " (original: " + path + ")"); - } - else { - logger.trace("Link not modified: " + path); - } - } - return new LineOutput((newPath != null ? newPath : path), appCacheResource); } @@ -261,9 +248,6 @@ public class AppCacheManifestTransformer extends ResourceTransformerSupport { public TransformedResource createResource() { String hash = DigestUtils.md5DigestAsHex(this.baos.toByteArray()); this.writer.write("\n" + "# Hash: " + hash); - if (logger.isTraceEnabled()) { - logger.trace("AppCache file: [" + resource.getFilename()+ "] hash: [" + hash + "]"); - } byte[] bytes = this.writer.toString().getBytes(DEFAULT_CHARSET); return new TransformedResource(this.resource, bytes); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/CachingResourceResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/CachingResourceResolver.java index 6cf3c3db38..ec49431556 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/CachingResourceResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/CachingResourceResolver.java @@ -110,16 +110,13 @@ public class CachingResourceResolver extends AbstractResourceResolver { if (resource != null) { if (logger.isTraceEnabled()) { - logger.trace("Found match: " + resource); + logger.trace("Resource resolved from cache"); } return resource; } resource = chain.resolveResource(request, requestPath, locations); if (resource != null) { - if (logger.isTraceEnabled()) { - logger.trace("Putting resolved resource in cache: " + resource); - } this.cache.put(key, resource); } @@ -163,16 +160,13 @@ public class CachingResourceResolver extends AbstractResourceResolver { if (resolvedUrlPath != null) { if (logger.isTraceEnabled()) { - logger.trace("Found match: \"" + resolvedUrlPath + "\""); + logger.trace("Path resolved from cache"); } return resolvedUrlPath; } resolvedUrlPath = chain.resolveUrlPath(resourceUrlPath, locations); if (resolvedUrlPath != null) { - if (logger.isTraceEnabled()) { - logger.trace("Putting resolved resource URL path in cache: \"" + resolvedUrlPath + "\""); - } this.cache.put(key, resolvedUrlPath); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/CachingResourceTransformer.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/CachingResourceTransformer.java index 6bb06869ad..4adf5b7a91 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/CachingResourceTransformer.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/CachingResourceTransformer.java @@ -72,16 +72,12 @@ public class CachingResourceTransformer implements ResourceTransformer { Resource transformed = this.cache.get(resource, Resource.class); if (transformed != null) { if (logger.isTraceEnabled()) { - logger.trace("Found match: " + transformed); + logger.trace("Resource resolved from cache"); } return transformed; } transformed = transformerChain.transform(request, resource); - - if (logger.isTraceEnabled()) { - logger.trace("Putting transformed resource in cache: " + transformed); - } this.cache.put(resource, transformed); return transformed; diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/CssLinkResourceTransformer.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/CssLinkResourceTransformer.java index 5b24349060..5f0483e58e 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/CssLinkResourceTransformer.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/CssLinkResourceTransformer.java @@ -76,10 +76,6 @@ public class CssLinkResourceTransformer extends ResourceTransformerSupport { return resource; } - if (logger.isTraceEnabled()) { - logger.trace("Transforming resource: " + resource); - } - byte[] bytes = FileCopyUtils.copyToByteArray(resource.getInputStream()); String content = new String(bytes, DEFAULT_CHARSET); @@ -89,9 +85,6 @@ public class CssLinkResourceTransformer extends ResourceTransformerSupport { } if (links.isEmpty()) { - if (logger.isTraceEnabled()) { - logger.trace("No links found."); - } return resource; } @@ -105,14 +98,6 @@ public class CssLinkResourceTransformer extends ResourceTransformerSupport { String absolutePath = toAbsolutePath(link, request); newLink = resolveUrlPath(absolutePath, request, resource, transformerChain); } - if (logger.isTraceEnabled()) { - if (newLink != null && !newLink.equals(link)) { - logger.trace("Link modified: " + newLink + " (original: " + link + ")"); - } - else { - logger.trace("Link not modified: " + link); - } - } writer.write(newLink != null ? newLink : link); index = linkContentChunkInfo.getEnd(); } @@ -197,8 +182,8 @@ public class CssLinkResourceTransformer extends ResourceTransformerSupport { if (content.substring(index, index + 4).equals("url(")) { // Ignore, UrlLinkParser will take care } - else if (logger.isErrorEnabled()) { - logger.error("Unexpected syntax for @import link at index " + index); + else if (logger.isWarnEnabled()) { + logger.warn("Unexpected syntax for @import link at index " + index); } return index; } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/GzipResourceResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/GzipResourceResolver.java index 5866d68b41..1d28a28fcf 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/GzipResourceResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/GzipResourceResolver.java @@ -61,7 +61,7 @@ public class GzipResourceResolver extends AbstractResourceResolver { } } catch (IOException ex) { - logger.trace("No gzipped resource for [" + resource.getFilename() + "]", ex); + logger.trace("No gzip resource for [" + resource.getFilename() + "]", ex); } return resource; diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/PathResourceResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/PathResourceResolver.java index 3125ea1926..8bea6d97fb 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/PathResourceResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/PathResourceResolver.java @@ -150,23 +150,14 @@ public class PathResourceResolver extends AbstractResourceResolver { for (Resource location : locations) { try { - if (logger.isTraceEnabled()) { - logger.trace("Checking location: " + location); - } String pathToUse = encodeIfNecessary(resourcePath, request, location); Resource resource = getResource(pathToUse, location); if (resource != null) { - if (logger.isTraceEnabled()) { - logger.trace("Found match: " + resource); - } return resource; } - else if (logger.isTraceEnabled()) { - logger.trace("No match for location: " + location); - } } catch (IOException ex) { - logger.trace("Failure checking for relative resource - trying next location", ex); + logger.trace("Failed to get resource, skipping location: " + location, ex); } } return null; @@ -187,9 +178,9 @@ public class PathResourceResolver extends AbstractResourceResolver { if (checkResource(resource, location)) { return resource; } - else if (logger.isTraceEnabled()) { + else if (logger.isWarnEnabled()) { Resource[] allowedLocations = getAllowedLocations(); - logger.trace("Resource path \"" + resourcePath + "\" was successfully resolved " + + logger.warn("Resource path \"" + resourcePath + "\" was successfully resolved " + "but resource \"" + resource.getURL() + "\" is neither under the " + "current location \"" + location.getURL() + "\" nor under any of the " + "allowed locations " + (allowedLocations != null ? Arrays.asList(allowedLocations) : "[]")); diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/ResourceHttpRequestHandler.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/ResourceHttpRequestHandler.java index f119cb6f21..98ae0cc60a 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/ResourceHttpRequestHandler.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/ResourceHttpRequestHandler.java @@ -21,9 +21,11 @@ import java.io.UnsupportedEncodingException; import java.net.URLDecoder; import java.nio.charset.Charset; import java.util.ArrayList; +import java.util.Collections; import java.util.HashMap; import java.util.List; import java.util.Map; +import java.util.stream.Collectors; import javax.servlet.ServletException; import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; @@ -448,7 +450,7 @@ public class ResourceHttpRequestHandler extends WebContentGenerator // For very general mappings (e.g. "/") we need to check 404 first Resource resource = getResource(request); if (resource == null) { - logger.trace("No matching resource found - returning 404"); + logger.trace("Resource not found"); response.sendError(HttpServletResponse.SC_NOT_FOUND); return; } @@ -463,7 +465,7 @@ public class ResourceHttpRequestHandler extends WebContentGenerator // Header phase if (new ServletWebRequest(request, response).checkNotModified(resource.lastModified())) { - logger.trace("Resource not modified - returning 304"); + logger.trace("Resource not modified"); return; } @@ -472,21 +474,10 @@ public class ResourceHttpRequestHandler extends WebContentGenerator // Check the media type for the resource MediaType mediaType = getMediaType(request, resource); - if (mediaType != null) { - if (logger.isTraceEnabled()) { - logger.trace("Determined media type '" + mediaType + "' for " + resource); - } - } - else { - if (logger.isTraceEnabled()) { - logger.trace("No media type found for " + resource + " - not sending a content-type header"); - } - } // Content phase if (METHOD_HEAD.equals(request.getMethod())) { setHeaders(response, resource, mediaType); - logger.trace("HEAD request - skipping content"); return; } @@ -597,9 +588,6 @@ public class ResourceHttpRequestHandler extends WebContentGenerator return path; } path = (slash ? "/" + path.substring(i) : path.substring(i)); - if (logger.isTraceEnabled()) { - logger.trace("Path after trimming leading '/' and control characters: [" + path + "]"); - } return path; } } @@ -649,20 +637,20 @@ public class ResourceHttpRequestHandler extends WebContentGenerator */ protected boolean isInvalidPath(String path) { if (path.contains("WEB-INF") || path.contains("META-INF")) { - logger.trace("Path contains \"WEB-INF\" or \"META-INF\"."); + logger.warn("Path contains \"WEB-INF\" or \"META-INF\"."); return true; } if (path.contains(":/")) { String relativePath = (path.charAt(0) == '/' ? path.substring(1) : path); if (ResourceUtils.isUrl(relativePath) || relativePath.startsWith("url:")) { - logger.trace("Path represents URL or has \"url:\" prefix."); + logger.warn("Path represents URL or has \"url:\" prefix."); return true; } } if (path.contains("..")) { path = StringUtils.cleanPath(path); if (path.contains("../")) { - logger.trace("Path contains \"../\" after call to StringUtils#cleanPath."); + logger.warn("Path contains \"../\" after call to StringUtils#cleanPath."); return true; } } @@ -727,7 +715,17 @@ public class ResourceHttpRequestHandler extends WebContentGenerator @Override public String toString() { - return "ResourceHttpRequestHandler [locations=" + getLocations() + ", resolvers=" + getResourceResolvers() + "]"; + return "ResourceHttpRequestHandler " + formatLocations(); + } + + private Object formatLocations() { + if (!this.locationValues.isEmpty()) { + return this.locationValues.stream().collect(Collectors.joining("\", \"", "[\"", "\"]")); + } + else if (!this.locations.isEmpty()) { + return this.locations; + } + return Collections.emptyList(); } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/ResourceUrlEncodingFilter.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/ResourceUrlEncodingFilter.java index f00b39e946..ce289c335e 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/ResourceUrlEncodingFilter.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/ResourceUrlEncodingFilter.java @@ -80,7 +80,8 @@ public class ResourceUrlEncodingFilter extends GenericFilterBean { public String encodeURL(String url) { ResourceUrlProvider resourceUrlProvider = getResourceUrlProvider(); if (resourceUrlProvider == null) { - logger.debug("Request attribute exposing ResourceUrlProvider not found"); + logger.trace("ResourceUrlProvider not available via " + + "request attribute ResourceUrlProviderExposingInterceptor.RESOURCE_URL_PROVIDER_ATTR"); return super.encodeURL(url); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/ResourceUrlProvider.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/ResourceUrlProvider.java index 53b828b945..9b99f84ba6 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/ResourceUrlProvider.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/resource/ResourceUrlProvider.java @@ -129,9 +129,6 @@ public class ResourceUrlProvider implements ApplicationListener beans = appContext.getBeansOfType(SimpleUrlHandlerMapping.class); List mappings = new ArrayList<>(beans.values()); AnnotationAwareOrderComparator.sort(mappings); @@ -151,15 +146,14 @@ public class ResourceUrlProvider implements ApplicationListener= suffixIndex) { @@ -229,10 +220,6 @@ public class ResourceUrlProvider implements ApplicationListener matchingPatterns = new ArrayList<>(); for (String pattern : this.handlerMap.keySet()) { if (getPathMatcher().match(pattern, lookupPath)) { @@ -246,25 +233,20 @@ public class ResourceUrlProvider implements ApplicationListener mapsToRemove = getExpiredFlashMaps(allFlashMaps); FlashMap match = getMatchingFlashMap(allFlashMaps, request); if (match != null) { @@ -105,9 +102,6 @@ public abstract class AbstractFlashMapManager implements FlashMapManager { } if (!mapsToRemove.isEmpty()) { - if (logger.isDebugEnabled()) { - logger.debug("Removing FlashMap(s): " + mapsToRemove); - } Object mutex = getFlashMapsMutex(request); if (mutex != null) { synchronized (mutex) { @@ -154,8 +148,8 @@ public abstract class AbstractFlashMapManager implements FlashMapManager { } if (!result.isEmpty()) { Collections.sort(result); - if (logger.isDebugEnabled()) { - logger.debug("Found matching FlashMap(s): " + result); + if (logger.isTraceEnabled()) { + logger.trace("Found " + result.get(0)); } return result.get(0); } @@ -204,9 +198,6 @@ public abstract class AbstractFlashMapManager implements FlashMapManager { String path = decodeAndNormalizePath(flashMap.getTargetRequestPath(), request); flashMap.setTargetRequestPath(path); - if (logger.isDebugEnabled()) { - logger.debug("Saving FlashMap=" + flashMap); - } flashMap.startExpirationPeriod(getFlashMapTimeout()); Object mutex = getFlashMapsMutex(request); diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/AbstractCachingViewResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/AbstractCachingViewResolver.java index 742ed7b3a7..3e03c037f1 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/AbstractCachingViewResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/AbstractCachingViewResolver.java @@ -164,17 +164,23 @@ public abstract class AbstractCachingViewResolver extends WebApplicationObjectSu if (view != null) { this.viewAccessCache.put(cacheKey, view); this.viewCreationCache.put(cacheKey, view); - if (logger.isTraceEnabled()) { - logger.trace("Cached view [" + cacheKey + "]"); - } } } } } + else { + if (logger.isTraceEnabled()) { + logger.trace(formatKey(cacheKey) + "served from cache"); + } + } return (view != UNRESOLVED_VIEW ? view : null); } } + private static String formatKey(Object cacheKey) { + return "View with key [" + cacheKey + "] "; + } + /** * Return the cache key for the given view name and the given locale. *

Default is a String consisting of view name and locale suffix. @@ -197,7 +203,7 @@ public abstract class AbstractCachingViewResolver extends WebApplicationObjectSu */ public void removeFromCache(String viewName, Locale locale) { if (!isCache()) { - logger.warn("View caching is SWITCHED OFF -- removal not necessary"); + logger.warn("Caching is OFF (removal not necessary)"); } else { Object cacheKey = getCacheKey(viewName, locale); @@ -208,12 +214,8 @@ public abstract class AbstractCachingViewResolver extends WebApplicationObjectSu } if (logger.isDebugEnabled()) { // Some debug output might be useful... - if (cachedView == null) { - logger.debug("No cached instance for view '" + cacheKey + "' was found"); - } - else { - logger.debug("Cache for view " + cacheKey + " has been cleared"); - } + logger.debug(formatKey(cacheKey) + + (cachedView != null ? "cleared from cache" : "not found in the cache")); } } } @@ -223,7 +225,7 @@ public abstract class AbstractCachingViewResolver extends WebApplicationObjectSu * Subsequent resolve calls will lead to recreation of demanded view objects. */ public void clearCache() { - logger.debug("Clearing entire view cache"); + logger.debug("Clearing all views from the cache"); synchronized (this.viewCreationCache) { this.viewAccessCache.clear(); this.viewCreationCache.clear(); diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/AbstractTemplateView.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/AbstractTemplateView.java index e8d00d273f..7dbe264883 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/AbstractTemplateView.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/AbstractTemplateView.java @@ -17,6 +17,7 @@ package org.springframework.web.servlet.view; import java.util.Enumeration; +import java.util.LinkedHashMap; import java.util.Map; import javax.servlet.ServletException; import javax.servlet.http.HttpServletRequest; @@ -115,6 +116,7 @@ public abstract class AbstractTemplateView extends AbstractUrlBasedView { Map model, HttpServletRequest request, HttpServletResponse response) throws Exception { if (this.exposeRequestAttributes) { + Map exposed = null; for (Enumeration en = request.getAttributeNames(); en.hasMoreElements();) { String attribute = en.nextElement(); if (model.containsKey(attribute) && !this.allowRequestOverride) { @@ -123,16 +125,20 @@ public abstract class AbstractTemplateView extends AbstractUrlBasedView { } Object attributeValue = request.getAttribute(attribute); if (logger.isDebugEnabled()) { - logger.debug("Exposing request attribute '" + attribute + - "' with value [" + attributeValue + "] to model"); + exposed = exposed != null ? exposed : new LinkedHashMap<>(); + exposed.put(attribute, attributeValue); } model.put(attribute, attributeValue); } + if (logger.isTraceEnabled() && exposed != null) { + logger.trace("Exposed request attributes to model: " + exposed); + } } if (this.exposeSessionAttributes) { HttpSession session = request.getSession(false); if (session != null) { + Map exposed = null; for (Enumeration en = session.getAttributeNames(); en.hasMoreElements();) { String attribute = en.nextElement(); if (model.containsKey(attribute) && !this.allowSessionOverride) { @@ -141,11 +147,14 @@ public abstract class AbstractTemplateView extends AbstractUrlBasedView { } Object attributeValue = session.getAttribute(attribute); if (logger.isDebugEnabled()) { - logger.debug("Exposing session attribute '" + attribute + - "' with value [" + attributeValue + "] to model"); + exposed = exposed != null ? exposed : new LinkedHashMap<>(); + exposed.put(attribute, attributeValue); } model.put(attribute, attributeValue); } + if (logger.isTraceEnabled() && exposed != null) { + logger.trace("Exposed session attributes to model: " + exposed); + } } } @@ -162,6 +171,10 @@ public abstract class AbstractTemplateView extends AbstractUrlBasedView { applyContentType(response); + if (logger.isDebugEnabled()) { + logger.debug("Rendering [" + getUrl() + "]"); + } + renderMergedTemplateModel(model, request, response); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/AbstractView.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/AbstractView.java index c39783726f..3a34bf1a69 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/AbstractView.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/AbstractView.java @@ -138,7 +138,8 @@ public abstract class AbstractView extends WebApplicationObjectSupport implement String tok = st.nextToken(); int eqIdx = tok.indexOf('='); if (eqIdx == -1) { - throw new IllegalArgumentException("Expected = in attributes CSV string '" + propString + "'"); + throw new IllegalArgumentException( + "Expected '=' in attributes CSV string '" + propString + "'"); } if (eqIdx >= tok.length() - 2) { throw new IllegalArgumentException( @@ -304,9 +305,10 @@ public abstract class AbstractView extends WebApplicationObjectSupport implement public void render(@Nullable Map model, HttpServletRequest request, HttpServletResponse response) throws Exception { - if (logger.isTraceEnabled()) { - logger.trace("Rendering view with name '" + this.beanName + "' with model " + model + - " and static attributes " + this.staticAttributes); + if (logger.isDebugEnabled()) { + logger.debug("View " + formatViewName() + + ", model " + (model != null ? model : Collections.emptyMap()) + + (this.staticAttributes.isEmpty() ? "" : ", static attributes " + this.staticAttributes)); } Map mergedModel = createMergedOutputModel(model, request, response); @@ -437,20 +439,12 @@ public abstract class AbstractView extends WebApplicationObjectSupport implement protected void exposeModelAsRequestAttributes(Map model, HttpServletRequest request) throws Exception { - model.forEach((modelName, modelValue) -> { - if (modelValue != null) { - request.setAttribute(modelName, modelValue); - if (logger.isDebugEnabled()) { - logger.debug("Added model object '" + modelName + "' of type [" + modelValue.getClass().getName() + - "] to request in view with name '" + getBeanName() + "'"); - } + model.forEach((name, value) -> { + if (value != null) { + request.setAttribute(name, value); } else { - request.removeAttribute(modelName); - if (logger.isDebugEnabled()) { - logger.debug("Removed model object '" + modelName + - "' from request in view with name '" + getBeanName() + "'"); - } + request.removeAttribute(name); } }); } @@ -499,14 +493,11 @@ public abstract class AbstractView extends WebApplicationObjectSupport implement @Override public String toString() { - StringBuilder sb = new StringBuilder(getClass().getName()); - if (getBeanName() != null) { - sb.append(": name '").append(getBeanName()).append("'"); - } - else { - sb.append(": unnamed"); - } - return sb.toString(); + return getClass().getName() + ": " + formatViewName(); + } + + protected String formatViewName() { + return (getBeanName() != null ? "name '" + getBeanName() + "'" : "[unnamed]"); } } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/BeanNameViewResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/BeanNameViewResolver.java index a645f34c64..657a5ed91d 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/BeanNameViewResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/BeanNameViewResolver.java @@ -77,16 +77,12 @@ public class BeanNameViewResolver extends WebApplicationObjectSupport implements public View resolveViewName(String viewName, Locale locale) throws BeansException { ApplicationContext context = obtainApplicationContext(); if (!context.containsBean(viewName)) { - if (logger.isDebugEnabled()) { - logger.debug("No matching bean found for view name '" + viewName + "'"); - } // Allow for ViewResolver chaining... return null; } if (!context.isTypeMatch(viewName, View.class)) { if (logger.isDebugEnabled()) { - logger.debug("Found matching bean for view name '" + viewName + - "' - to be ignored since it does not implement View"); + logger.debug("Found bean named '" + viewName + "' but it does not implement View"); } // Since we're looking into the general ApplicationContext here, // let's accept this as a non-match and allow for chaining as well... diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/ContentNegotiatingViewResolver.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/ContentNegotiatingViewResolver.java index d8bfc12916..9d64c91204 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/ContentNegotiatingViewResolver.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/ContentNegotiatingViewResolver.java @@ -202,10 +202,6 @@ public class ContentNegotiatingViewResolver extends WebApplicationObjectSupport } } - if (this.viewResolvers.isEmpty()) { - logger.warn("Did not find any ViewResolvers to delegate to; please configure them using the " + - "'viewResolvers' property on the ContentNegotiatingViewResolver"); - } AnnotationAwareOrderComparator.sort(this.viewResolvers); this.cnmFactoryBean.setServletContext(servletContext); } @@ -215,6 +211,9 @@ public class ContentNegotiatingViewResolver extends WebApplicationObjectSupport if (this.contentNegotiationManager == null) { this.contentNegotiationManager = this.cnmFactoryBean.build(); } + if (this.viewResolvers == null || this.viewResolvers.isEmpty()) { + logger.warn("No ViewResolvers configured"); + } } @@ -231,14 +230,18 @@ public class ContentNegotiatingViewResolver extends WebApplicationObjectSupport return bestView; } } + + String mediaTypeInfo = logger.isDebugEnabled() && requestedMediaTypes != null ? + " given " + requestedMediaTypes.toString() : ""; + if (this.useNotAcceptableStatusCode) { if (logger.isDebugEnabled()) { - logger.debug("No acceptable view found; returning 406 (Not Acceptable) status code"); + logger.debug("Using 406 NOT_ACCEPTABLE" + mediaTypeInfo); } return NOT_ACCEPTABLE_VIEW; } else { - logger.debug("No acceptable view found; returning null"); + logger.debug("View remains unresolved" + mediaTypeInfo); return null; } } @@ -265,13 +268,12 @@ public class ContentNegotiatingViewResolver extends WebApplicationObjectSupport } List selectedMediaTypes = new ArrayList<>(compatibleMediaTypes); MediaType.sortBySpecificityAndQuality(selectedMediaTypes); - if (logger.isDebugEnabled()) { - logger.debug("Requested media types are " + selectedMediaTypes + " based on Accept header types " + - "and producible media types " + producibleMediaTypes + ")"); - } return selectedMediaTypes; } catch (HttpMediaTypeNotAcceptableException ex) { + if (logger.isDebugEnabled()) { + logger.debug(ex.getMessage()); + } return null; } } @@ -332,9 +334,6 @@ public class ContentNegotiatingViewResolver extends WebApplicationObjectSupport if (candidateView instanceof SmartView) { SmartView smartView = (SmartView) candidateView; if (smartView.isRedirectView()) { - if (logger.isDebugEnabled()) { - logger.debug("Returning redirect view [" + candidateView + "]"); - } return candidateView; } } @@ -345,8 +344,7 @@ public class ContentNegotiatingViewResolver extends WebApplicationObjectSupport MediaType candidateContentType = MediaType.parseMediaType(candidateView.getContentType()); if (mediaType.isCompatibleWith(candidateContentType)) { if (logger.isDebugEnabled()) { - logger.debug("Returning [" + candidateView + "] based on requested media type '" + - mediaType + "'"); + logger.debug("Selected '" + mediaType + "' given " + requestedMediaTypes); } attrs.setAttribute(View.SELECTED_CONTENT_TYPE, mediaType, RequestAttributes.SCOPE_REQUEST); return candidateView; diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/InternalResourceView.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/InternalResourceView.java index 1fe7eeccfa..d789b8aae2 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/InternalResourceView.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/InternalResourceView.java @@ -157,7 +157,7 @@ public class InternalResourceView extends AbstractUrlBasedView { if (useInclude(request, response)) { response.setContentType(getContentType()); if (logger.isDebugEnabled()) { - logger.debug("Including resource [" + getUrl() + "] in InternalResourceView '" + getBeanName() + "'"); + logger.debug("Including [" + getUrl() + "]"); } rd.include(request, response); } @@ -165,7 +165,7 @@ public class InternalResourceView extends AbstractUrlBasedView { else { // Note: The forwarded resource is supposed to determine the content type itself. if (logger.isDebugEnabled()) { - logger.debug("Forwarding to resource [" + getUrl() + "] in InternalResourceView '" + getBeanName() + "'"); + logger.debug("Forwarding to [" + getUrl() + "]"); } rd.forward(request, response); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/freemarker/FreeMarkerConfigurer.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/freemarker/FreeMarkerConfigurer.java index 6e0b746664..fb622a866d 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/freemarker/FreeMarkerConfigurer.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/freemarker/FreeMarkerConfigurer.java @@ -128,7 +128,7 @@ public class FreeMarkerConfigurer extends FreeMarkerConfigurationFactory @Override protected void postProcessTemplateLoaders(List templateLoaders) { templateLoaders.add(new ClassTemplateLoader(FreeMarkerConfigurer.class, "")); - logger.info("ClassTemplateLoader for Spring macros added to FreeMarker configuration"); + logger.trace("ClassTemplateLoader for Spring FreeMarker macros added"); } diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/freemarker/FreeMarkerView.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/freemarker/FreeMarkerView.java index c843e8c0b8..896bf3f87e 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/freemarker/FreeMarkerView.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/freemarker/FreeMarkerView.java @@ -228,18 +228,14 @@ public class FreeMarkerView extends AbstractTemplateView { return true; } catch (FileNotFoundException ex) { - if (logger.isDebugEnabled()) { - logger.debug("No FreeMarker view found for URL: " + url); - } + // Allow for ViewResolver chaining... return false; } catch (ParseException ex) { - throw new ApplicationContextException( - "Failed to parse FreeMarker template for URL [" + url + "]", ex); + throw new ApplicationContextException("Failed to parse [" + url + "]", ex); } catch (IOException ex) { - throw new ApplicationContextException( - "Could not load FreeMarker template for URL [" + url + "]", ex); + throw new ApplicationContextException("Failed to load [" + url + "]", ex); } } @@ -301,9 +297,6 @@ public class FreeMarkerView extends AbstractTemplateView { // Expose all standard FreeMarker hash models. SimpleHash fmModel = buildTemplateModel(model, request, response); - if (logger.isDebugEnabled()) { - logger.debug("Rendering FreeMarker template [" + getUrl() + "] in FreeMarkerView '" + getBeanName() + "'"); - } // Grab the locale-specific version of the template. Locale locale = RequestContextUtils.getLocale(request); processTemplate(getTemplate(locale), fmModel, response); diff --git a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/xslt/XsltView.java b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/xslt/XsltView.java index f7167ba42d..54eb49f786 100644 --- a/spring-webmvc/src/main/java/org/springframework/web/servlet/view/xslt/XsltView.java +++ b/spring-webmvc/src/main/java/org/springframework/web/servlet/view/xslt/XsltView.java @@ -428,9 +428,6 @@ public class XsltView extends AbstractUrlBasedView { Source stylesheetSource = getStylesheetSource(); try { Templates templates = getTransformerFactory().newTemplates(stylesheetSource); - if (logger.isDebugEnabled()) { - logger.debug("Loading templates '" + templates + "'"); - } return templates; } catch (TransformerConfigurationException ex) { @@ -466,7 +463,7 @@ public class XsltView extends AbstractUrlBasedView { Assert.state(url != null, "'url' not set"); if (logger.isDebugEnabled()) { - logger.debug("Loading XSLT stylesheet from '" + url + "'"); + logger.debug("Applying stylesheet [" + url + "]"); } try { Resource resource = obtainApplicationContext().getResource(url); diff --git a/spring-webmvc/src/test/java/org/springframework/web/servlet/mvc/annotation/CglibProxyControllerTests.java b/spring-webmvc/src/test/java/org/springframework/web/servlet/mvc/annotation/CglibProxyControllerTests.java index ca1deded49..c96c96e63e 100644 --- a/spring-webmvc/src/test/java/org/springframework/web/servlet/mvc/annotation/CglibProxyControllerTests.java +++ b/spring-webmvc/src/test/java/org/springframework/web/servlet/mvc/annotation/CglibProxyControllerTests.java @@ -22,9 +22,11 @@ import javax.servlet.ServletException; import org.junit.Test; +import org.springframework.aop.Pointcut; import org.springframework.aop.framework.autoproxy.DefaultAdvisorAutoProxyCreator; import org.springframework.aop.interceptor.SimpleTraceInterceptor; import org.springframework.aop.support.DefaultPointcutAdvisor; +import org.springframework.aop.support.annotation.AnnotationMatchingPointcut; import org.springframework.beans.factory.support.RootBeanDefinition; import org.springframework.lang.Nullable; import org.springframework.mock.web.test.MockHttpServletRequest; @@ -89,7 +91,9 @@ public class CglibProxyControllerTests { autoProxyCreator.setProxyTargetClass(true); autoProxyCreator.setBeanFactory(wac.getBeanFactory()); wac.getBeanFactory().addBeanPostProcessor(autoProxyCreator); - wac.getBeanFactory().registerSingleton("advisor", new DefaultPointcutAdvisor(new SimpleTraceInterceptor(true))); + Pointcut pointcut = new AnnotationMatchingPointcut(Controller.class); + DefaultPointcutAdvisor advisor = new DefaultPointcutAdvisor(pointcut, new SimpleTraceInterceptor(true)); + wac.getBeanFactory().registerSingleton("advisor", advisor); wac.refresh(); return wac; } diff --git a/spring-webmvc/src/test/java/org/springframework/web/servlet/view/ContentNegotiatingViewResolverTests.java b/spring-webmvc/src/test/java/org/springframework/web/servlet/view/ContentNegotiatingViewResolverTests.java index d79f8076ea..8046cc267b 100644 --- a/spring-webmvc/src/test/java/org/springframework/web/servlet/view/ContentNegotiatingViewResolverTests.java +++ b/spring-webmvc/src/test/java/org/springframework/web/servlet/view/ContentNegotiatingViewResolverTests.java @@ -134,7 +134,10 @@ public class ContentNegotiatingViewResolverTests { public void resolveViewNameWithInvalidAcceptHeader() throws Exception { request.addHeader("Accept", "application"); + ViewResolver viewResolverMock = mock(ViewResolver.class); + viewResolver.setViewResolvers(Collections.singletonList(viewResolverMock)); viewResolver.afterPropertiesSet(); + View result = viewResolver.resolveViewName("test", Locale.ENGLISH); assertNull(result); } diff --git a/src/docs/asciidoc/web/webmvc.adoc b/src/docs/asciidoc/web/webmvc.adoc index e1ab3d67d9..a830d34a22 100644 --- a/src/docs/asciidoc/web/webmvc.adoc +++ b/src/docs/asciidoc/web/webmvc.adoc @@ -3272,26 +3272,8 @@ such headers. [[mvc-links-to-controllers-from-views]] === Links in views -You can also build links to annotated controllers from views such as JSP, Thymeleaf, -FreeMarker. This can be done using the `fromMappingName` method in `MvcUriComponentsBuilder` -which refers to mappings by name. - -Every `@RequestMapping` is assigned a default name based on the capital letters of the -class and the full method name. For example, the method `getFoo` in class `FooController` -is assigned the name "FC#getFoo". This strategy can be replaced or customized by creating -an instance of `HandlerMethodMappingNamingStrategy` and plugging it into your -`RequestMappingHandlerMapping`. The default strategy implementation also looks at the -name attribute on `@RequestMapping` and uses that if present. That means if the default -mapping name assigned conflicts with another (e.g. overloaded methods) you can assign -a name explicitly on the `@RequestMapping`. - -[NOTE] -==== -The assigned request mapping names are logged at TRACE level on startup. -==== - -The Spring JSP tag library provides a function called `mvcUrl` that can be used to -prepare links to controller methods based on this mechanism. +In views such as Thymeleaf, FreeMarker, JSP you can build links to annotated controllers +by referring to the implicitly or explicitly assigned name for each request mapping. For example given: @@ -3316,10 +3298,16 @@ You can prepare a link from a JSP as follows: Get Address ---- -The above example relies on the `mvcUrl` JSP function declared in the Spring tag library -(i.e. META-INF/spring.tld). For more advanced cases (e.g. a custom base URL as explained -in the previous section), it is easy to define your own function, or use a custom tag file, -in order to use a specific instance of `MvcUriComponentsBuilder` with a custom base URL. +The above example relies on the `mvcUrl` function declared in the Spring tag library +(i.e. META-INF/spring.tld), but it is easy to define your own function, or prepare a +similar one for other templating technologies. + +Here is how this works. On startup every `@RequestMapping` is assigned a default name +through a `HandlerMethodMappingNamingStrategy` whose default implementation uses the +capital letters of the class and the method name, e.g. the `getFoo` method in +`FooController` becomes "FC#getFoo". If there is a name clash you can use +`@RequestMapping(name="..")` to assign an explicit name, or implement your own +`HandlerMethodMappingNamingStrategy`.