From 14d0fee86c207df1d88ac63ff159d06337f34817 Mon Sep 17 00:00:00 2001 From: Rossen Stoyanchev Date: Wed, 25 Jul 2018 17:50:03 -0400 Subject: [PATCH] Improve context-related logging on web startup Sample output at TRACE: ``` DispatcherServlet - Initializing Servlet 'org.springframework.web.servlet.DispatcherServlet-7a8c8dcf' AnnotationConfigWebApplicationContext - Refreshing WebApplicationContext for namespace 'org.springframework.web.servlet.DispatcherServlet-7a8c8dcf-servlet', started on Wed Jul 25 17:46:38 EDT 2018 AnnotationConfigWebApplicationContext - Registering [org.springframework.web.servlet.mvc.method.annotation.RequestPartIntegrationTests$CommonsMultipartResolverTestConfig] AnnotationConfigWebApplicationContext - No 'messageSource' bean, using [Empty MessageSource] AnnotationConfigWebApplicationContext - No 'applicationEventMulticaster' bean, using [SimpleApplicationEventMulticaster] AnnotationConfigWebApplicationContext - No 'lifecycleProcessor' bean, using [DefaultLifecycleProcessor] ... DispatcherServlet - Initialization completed in 3361 ms ``` Issue: SPR-16946 --- .../support/AbstractApplicationContext.java | 30 +++++++++---------- .../support/DelegatingMessageSource.java | 6 ++++ .../web/context/ContextLoader.java | 2 +- ...AnnotationConfigWebApplicationContext.java | 2 +- .../web/servlet/FrameworkServlet.java | 23 ++------------ .../web/servlet/HttpServletBean.java | 7 ----- 6 files changed, 25 insertions(+), 45 deletions(-) diff --git a/spring-context/src/main/java/org/springframework/context/support/AbstractApplicationContext.java b/spring-context/src/main/java/org/springframework/context/support/AbstractApplicationContext.java index ba60fa82e60..4960850eab0 100644 --- a/spring-context/src/main/java/org/springframework/context/support/AbstractApplicationContext.java +++ b/spring-context/src/main/java/org/springframework/context/support/AbstractApplicationContext.java @@ -585,7 +585,12 @@ public abstract class AbstractApplicationContext extends DefaultResourceLoader this.active.set(true); if (logger.isDebugEnabled()) { - logger.debug("Refreshing " + this); + if (logger.isTraceEnabled()) { + logger.trace("Refreshing " + this); + } + else { + logger.debug("Refreshing " + getDisplayName()); + } } // Initialize any placeholder property sources in the context environment @@ -732,8 +737,7 @@ public abstract class AbstractApplicationContext extends DefaultResourceLoader this.messageSource = dms; beanFactory.registerSingleton(MESSAGE_SOURCE_BEAN_NAME, this.messageSource); if (logger.isTraceEnabled()) { - logger.trace("Unable to locate MessageSource with name '" + MESSAGE_SOURCE_BEAN_NAME + - "': using default [" + this.messageSource + "]"); + logger.trace("No '" + MESSAGE_SOURCE_BEAN_NAME + "' bean, using [" + this.messageSource + "]"); } } } @@ -756,9 +760,8 @@ public abstract class AbstractApplicationContext extends DefaultResourceLoader this.applicationEventMulticaster = new SimpleApplicationEventMulticaster(beanFactory); beanFactory.registerSingleton(APPLICATION_EVENT_MULTICASTER_BEAN_NAME, this.applicationEventMulticaster); if (logger.isTraceEnabled()) { - logger.trace("Unable to locate ApplicationEventMulticaster with name '" + - APPLICATION_EVENT_MULTICASTER_BEAN_NAME + - "': using default [" + this.applicationEventMulticaster + "]"); + logger.trace("No '" + APPLICATION_EVENT_MULTICASTER_BEAN_NAME + "' bean, using " + + "[" + this.applicationEventMulticaster.getClass().getSimpleName() + "]"); } } } @@ -783,9 +786,8 @@ public abstract class AbstractApplicationContext extends DefaultResourceLoader this.lifecycleProcessor = defaultProcessor; beanFactory.registerSingleton(LIFECYCLE_PROCESSOR_BEAN_NAME, this.lifecycleProcessor); if (logger.isTraceEnabled()) { - logger.trace("Unable to locate LifecycleProcessor with name '" + - LIFECYCLE_PROCESSOR_BEAN_NAME + - "': using default [" + this.lifecycleProcessor + "]"); + logger.trace("No '" + LIFECYCLE_PROCESSOR_BEAN_NAME + "' bean, using " + + "[" + this.lifecycleProcessor.getClass().getSimpleName() + "]"); } } } @@ -1384,14 +1386,10 @@ public abstract class AbstractApplicationContext extends DefaultResourceLoader @Override public String toString() { StringBuilder sb = new StringBuilder(getDisplayName()); - sb.append(": startup date [").append(new Date(getStartupDate())); - sb.append("]; "); + sb.append(", started on ").append(new Date(getStartupDate())); ApplicationContext parent = getParent(); - if (parent == null) { - sb.append("root of context hierarchy"); - } - else { - sb.append("parent: ").append(parent.getDisplayName()); + if (parent != null) { + sb.append(", parent: ").append(parent.getDisplayName()); } return sb.toString(); } diff --git a/spring-context/src/main/java/org/springframework/context/support/DelegatingMessageSource.java b/spring-context/src/main/java/org/springframework/context/support/DelegatingMessageSource.java index 1556e5bf1ed..737f1036161 100644 --- a/spring-context/src/main/java/org/springframework/context/support/DelegatingMessageSource.java +++ b/spring-context/src/main/java/org/springframework/context/support/DelegatingMessageSource.java @@ -92,4 +92,10 @@ public class DelegatingMessageSource extends MessageSourceSupport implements Hie } } + + @Override + public String toString() { + return this.parentMessageSource != null ? this.parentMessageSource.toString() : "Empty MessageSource"; + } + } diff --git a/spring-web/src/main/java/org/springframework/web/context/ContextLoader.java b/spring-web/src/main/java/org/springframework/web/context/ContextLoader.java index 1a77e2f628f..c2bb14b8b74 100644 --- a/spring-web/src/main/java/org/springframework/web/context/ContextLoader.java +++ b/spring-web/src/main/java/org/springframework/web/context/ContextLoader.java @@ -303,7 +303,7 @@ public class ContextLoader { if (logger.isInfoEnabled()) { long elapsedTime = System.currentTimeMillis() - startTime; - logger.info("Root WebApplicationContext: initialization completed in " + elapsedTime + " ms"); + logger.info("Root WebApplicationContext initialized in " + elapsedTime + " ms"); } return this.context; diff --git a/spring-web/src/main/java/org/springframework/web/context/support/AnnotationConfigWebApplicationContext.java b/spring-web/src/main/java/org/springframework/web/context/support/AnnotationConfigWebApplicationContext.java index 028a693ccf1..55e2c8cfe5a 100644 --- a/spring-web/src/main/java/org/springframework/web/context/support/AnnotationConfigWebApplicationContext.java +++ b/spring-web/src/main/java/org/springframework/web/context/support/AnnotationConfigWebApplicationContext.java @@ -230,7 +230,7 @@ public class AnnotationConfigWebApplicationContext extends AbstractRefreshableWe try { Class clazz = ClassUtils.forName(configLocation, getClassLoader()); if (logger.isTraceEnabled()) { - logger.trace("Successfully resolved class for [" + configLocation + "]"); + logger.trace("Registering [" + configLocation + "]"); } reader.register(clazz); } 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 23f6cff1494..59217870d9b 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 @@ -516,9 +516,9 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic */ @Override protected final void initServletBean() throws ServletException { - getServletContext().log("Initializing Spring FrameworkServlet '" + getServletName() + "'"); + getServletContext().log("Initializing Spring " + getClass().getSimpleName() + " '" + getServletName() + "'"); if (logger.isInfoEnabled()) { - logger.info("FrameworkServlet '" + getServletName() + "': initialization started"); + logger.info("Initializing Servlet '" + getServletName() + "'"); } long startTime = System.currentTimeMillis(); @@ -540,9 +540,7 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic } if (logger.isInfoEnabled()) { - long elapsedTime = System.currentTimeMillis() - startTime; - logger.info("FrameworkServlet '" + getServletName() + "': initialization completed in " + - elapsedTime + " ms"); + logger.info("Completed initialization in " + (System.currentTimeMillis() - startTime) + " ms"); } } @@ -600,10 +598,6 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic // Publish the context as a servlet context attribute. String attrName = getServletContextAttributeName(); getServletContext().setAttribute(attrName, wac); - if (logger.isTraceEnabled()) { - logger.trace("Published WebApplicationContext of servlet '" + getServletName() + - "' as ServletContext attribute [" + attrName + "]"); - } } return wac; @@ -650,11 +644,6 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic */ protected WebApplicationContext createWebApplicationContext(@Nullable ApplicationContext parent) { Class contextClass = getContextClass(); - if (logger.isTraceEnabled()) { - logger.trace("Servlet '" + getServletName() + - "' will create custom WebApplicationContext context of class '" + - contextClass.getName() + "'" + ", parent context [" + parent + "]"); - } if (!ConfigurableWebApplicationContext.class.isAssignableFrom(contextClass)) { throw new ApplicationContextException( "Fatal initialization error in servlet with name '" + getServletName() + @@ -1071,9 +1060,6 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic if (requestAttributes != null) { RequestContextHolder.setRequestAttributes(requestAttributes, this.threadContextInheritable); } - if (logger.isTraceEnabled()) { - logger.trace("Bound request context to thread: " + request); - } } private void resetContextHolders(HttpServletRequest request, @@ -1081,9 +1067,6 @@ public abstract class FrameworkServlet extends HttpServletBean implements Applic LocaleContextHolder.setLocaleContext(prevLocaleContext, this.threadContextInheritable); RequestContextHolder.setRequestAttributes(previousAttributes, this.threadContextInheritable); - if (logger.isTraceEnabled()) { - logger.trace("Cleared thread-bound request context: " + request); - } } private void logResult(HttpServletRequest request, HttpServletResponse response, 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 15a6ea6ba88..65b9c4a3c77 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,9 +146,6 @@ public abstract class HttpServletBean extends HttpServlet implements Environment */ @Override public final void init() throws ServletException { - if (logger.isTraceEnabled()) { - logger.trace("Initializing servlet '" + getServletName() + "'"); - } // Set bean properties from init parameters. PropertyValues pvs = new ServletConfigPropertyValues(getServletConfig(), this.requiredProperties); @@ -170,10 +167,6 @@ public abstract class HttpServletBean extends HttpServlet implements Environment // Let subclasses do whatever initialization they like. initServletBean(); - - if (logger.isTraceEnabled()) { - logger.trace("Servlet '" + getServletName() + "' configured successfully"); - } } /**