What can I learn about my Spring MVC application by logging the Spring Framework?

You have probably noticed that a lot of stuff goes scrolling by when you startup your Spring Boot application, including some decent looking ASCII art.

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/

If this “boilerplate” section is too short, or “looks different”, or contains additional warnings or errors, this can often be your first clue that something has broken. Let’s take a closer look at what all this stuff means…

Sample Code In Spring-Boot

There are many “ready to go” Spring examples in the Spring Boot project on GitHub.

$ git clone https://github.com/spring-projects/spring-boot.git

For the purpose of this discussion, let’s take a look at this one:

$ cd ~/github/github/spring-boot/spring-boot-samples/spring-boot-sample-web-ui
$ mvn spring-boot:run

[INFO] Scanning for projects...
[INFO]
[INFO] ------------------------------------------------------------------------
[INFO] Building Spring Boot Web UI Sample 1.4.1.BUILD-SNAPSHOT
[INFO] ------------------------------------------------------------------------
[INFO]
[INFO] >>> spring-boot-maven-plugin:1.4.1.BUILD-SNAPSHOT:run (default-cli) > test-compile @ spring-boot-sample-web-ui >>>
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ spring-boot-sample-web-ui ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 1 resource
[INFO] Copying 9 resources
[INFO]
[INFO] --- maven-compiler-plugin:3.1:compile (default-compile) @ spring-boot-sample-web-ui ---
[INFO] Nothing to compile - all classes are up to date
[INFO]
[INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ spring-boot-sample-web-ui ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory /Users/example/github/spring-boot/spring-boot-samples/spring-boot-sample-web-ui/src/test/resources
[INFO]
[INFO] --- maven-compiler-plugin:3.1:testCompile (default-testCompile) @ spring-boot-sample-web-ui ---
[INFO] Nothing to compile - all classes are up to date
[INFO]
[INFO] <<< spring-boot-maven-plugin:1.4.1.BUILD-SNAPSHOT:run (default-cli) < test-compile @ spring-boot-sample-web-ui <<<
[INFO]
[INFO] --- spring-boot-maven-plugin:1.4.1.BUILD-SNAPSHOT:run (default-cli) @ spring-boot-sample-web-ui ---

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::  (v1.4.1.BUILD-SNAPSHOT)

2016-08-02 02:26:03.274  INFO 39785 --- [           main] sample.web.ui.SampleWebUiApplication     : Starting SampleWebUiApplication on example.fios-router.home with PID 39785 (/Users/example/github/spring-boot/spring-boot-samples/spring-boot-sample-web-ui/target/classes started by example in /Users/example/github/spring-boot/spring-boot-samples/spring-boot-sample-web-ui)
2016-08-02 02:26:03.277  INFO 39785 --- [           main] sample.web.ui.SampleWebUiApplication     : No active profile set, falling back to default profiles: default
2016-08-02 02:26:03.485  INFO 39785 --- [           main] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@3afa50d5: startup date [Tue Aug 02 02:26:03 EDT 2016]; root of context hierarchy
2016-08-02 02:26:04.474  INFO 39785 --- [           main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat initialized with port(s): 8080 (http)
2016-08-02 02:26:04.483  INFO 39785 --- [           main] o.apache.catalina.core.StandardService   : Starting service Tomcat
2016-08-02 02:26:04.484  INFO 39785 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet Engine: Apache Tomcat/8.5.4
2016-08-02 02:26:04.544  INFO 39785 --- [ost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2016-08-02 02:26:04.545  INFO 39785 --- [ost-startStop-1] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 1063 ms
2016-08-02 02:26:04.660  INFO 39785 --- [ost-startStop-1] o.s.b.w.servlet.ServletRegistrationBean  : Mapping servlet: 'dispatcherServlet' to [/]
2016-08-02 02:26:04.662  INFO 39785 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'characterEncodingFilter' to: [/*]
2016-08-02 02:26:04.663  INFO 39785 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]
2016-08-02 02:26:04.663  INFO 39785 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'httpPutFormContentFilter' to: [/*]
2016-08-02 02:26:04.663  INFO 39785 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'requestContextFilter' to: [/*]
2016-08-02 02:26:04.877  INFO 39785 --- [           main] s.w.s.m.m.a.RequestMappingHandlerAdapter : Looking for @ControllerAdvice: org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@3afa50d5: startup date [Tue Aug 02 02:26:03 EDT 2016]; root of context hierarchy
2016-08-02 02:26:04.938  INFO 39785 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/delete/{id}],methods=[GET]}" onto public org.springframework.web.servlet.ModelAndView sample.web.ui.mvc.MessageController.delete(java.lang.Long)
2016-08-02 02:26:04.939  INFO 39785 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/],methods=[POST]}" onto public org.springframework.web.servlet.ModelAndView sample.web.ui.mvc.MessageController.create(sample.web.ui.Message,org.springframework.validation.BindingResult,org.springframework.web.servlet.mvc.support.RedirectAttributes)
2016-08-02 02:26:04.939  INFO 39785 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/],methods=[GET]}" onto public org.springframework.web.servlet.ModelAndView sample.web.ui.mvc.MessageController.list()
2016-08-02 02:26:04.939  INFO 39785 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/{id}],methods=[GET]}" onto public org.springframework.web.servlet.ModelAndView sample.web.ui.mvc.MessageController.view(sample.web.ui.Message)
2016-08-02 02:26:04.940  INFO 39785 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/],methods=[GET],params=[form]}" onto public java.lang.String sample.web.ui.mvc.MessageController.createForm(sample.web.ui.Message)
2016-08-02 02:26:04.940  INFO 39785 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/foo]}" onto public java.lang.String sample.web.ui.mvc.MessageController.foo()
2016-08-02 02:26:04.940  INFO 39785 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/modify/{id}],methods=[GET]}" onto public org.springframework.web.servlet.ModelAndView sample.web.ui.mvc.MessageController.modifyForm(sample.web.ui.Message)
2016-08-02 02:26:04.942  INFO 39785 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error]}" onto public org.springframework.http.ResponseEntity<java.util.Map<java.lang.String, java.lang.Object>> org.springframework.boot.autoconfigure.web.BasicErrorController.error(javax.servlet.http.HttpServletRequest)
2016-08-02 02:26:04.942  INFO 39785 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error],produces=[text/html]}" onto public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)
2016-08-02 02:26:04.963  INFO 39785 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/webjars/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2016-08-02 02:26:04.964  INFO 39785 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2016-08-02 02:26:05.001  INFO 39785 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**/favicon.ico] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2016-08-02 02:26:05.323  INFO 39785 --- [           main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2016-08-02 02:26:05.374  INFO 39785 --- [           main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat started on port(s): 8080 (http)
2016-08-02 02:26:05.379  INFO 39785 --- [           main] sample.web.ui.SampleWebUiApplication     : Started SampleWebUiApplication in 2.399 seconds (JVM running for 4.804)

Without really trying, we are getting a lot of useful feedback for such a simple application.

The very first line of output gives us some useful information:

  • name of the host server (example-fios-router.home)
  • process id (40353)
  • classpath (/Users/example/github/spring-boot/spring-boot-samples/spring-boot-sample-web-ui/target/classes)
  • current user (example)
  • startup directory (/Users/example/github/spring-boot/spring-boot-samples/spring-boot-sample-web-ui)

In the above output you can see the following sequence of events:

  • Tomcat is started on port 8080 (Apache Tomcat/8.5.4 in this case)
  • WebApplicationContext initialization (completed in 2220 ms)
  • Tomcat servlet is registered to receive requests to path [/]
  • Various spring-related Servlet Filters are registered to intercept requests to the servlet.
  • @Controller annotations are found and mapped to specific controller methods
  • JMX support is enabled
  • Entire startup time is benchmarked (2.399 seconds)

This is a lot of useful information that could help with a quick sanity check if your controllers are not responding.

Pump Up The Volume

Pump Up The Volume

You may not realize this, but there’s a ton of debugging information in the org.springframework packages that you can just “turn on”.

What additional information can we get when we set the logging level of org.springframework to DEBUG? Let’s find out!

$ vi ./src/main/resources/logback.xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>

        <include resource="org/springframework/boot/logging/logback/base.xml"/>

        <!-- logger name="org.springframework" level="DEBUG"/-->

</configuration>

Let’s just uncomment that logger…

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

	<include resource="org/springframework/boot/logging/logback/base.xml"/>

	<logger name="org.springframework" level="DEBUG"/>

</configuration>

And see what we get this time (major sections omitted for brevity – try it for yourself to see everything):

$ mvn spring-boot:run
Picked up JAVA_TOOL_OPTIONS: -Djava.awt.headless=true
[INFO] Scanning for projects...
[INFO]
[INFO] ------------------------------------------------------------------------
[INFO] Building Spring Boot Web UI Sample 1.4.1.BUILD-SNAPSHOT
[INFO] ------------------------------------------------------------------------
[INFO]
[INFO] >>> spring-boot-maven-plugin:1.4.1.BUILD-SNAPSHOT:run (default-cli) > test-compile @ spring-boot-sample-web-ui >>>
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ spring-boot-sample-web-ui ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 1 resource
[INFO] Copying 9 resources
[INFO]
[INFO] --- maven-compiler-plugin:3.1:compile (default-compile) @ spring-boot-sample-web-ui ---
[INFO] Nothing to compile - all classes are up to date
[INFO]
[INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ spring-boot-sample-web-ui ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory /Users/example/github/spring-boot/spring-boot-samples/spring-boot-sample-web-ui/src/test/resources
[INFO]
[INFO] --- maven-compiler-plugin:3.1:testCompile (default-testCompile) @ spring-boot-sample-web-ui ---
[INFO] Nothing to compile - all classes are up to date
[INFO]
[INFO] <<< spring-boot-maven-plugin:1.4.1.BUILD-SNAPSHOT:run (default-cli) < test-compile @ spring-boot-sample-web-ui <<<
[INFO]
[INFO] --- spring-boot-maven-plugin:1.4.1.BUILD-SNAPSHOT:run (default-cli) @ spring-boot-sample-web-ui ---
2016-08-02 11:34:54.961 DEBUG 48156 --- [           main] .b.l.ClasspathLoggingApplicationListener : Application started with classpath: [file:/Users/example/github/spring-boot/spring-boot-samples/spring-boot-sample-web-ui/target/classes/, file:/Users/example/.m2/repository/org/springframework/boot/spring-boot/1.4.1.BUILD-SNAPSHOT/spring-boot-1.4.1.BUILD-SNAPSHOT.jar, file:/Users/example/.m2/repository/com/fasterxml/jackson/core/jackson-core/2.8.1/jackson-core-2.8.1.jar, file:/Users/example/.m2/repository/org/springframework/spring-web/4.3.2.RELEASE/spring-web-4.3.2.RELEASE.jar, file:/Users/example/.m2/repository/org/unbescape/unbescape/1.1.0.RELEASE/unbescape-1.1.0.RELEASE.jar, file:/Users/example/.m2/repository/org/javassist/javassist/3.20.0-GA/javassist-3.20.0-GA.jar, file:/Users/example/.m2/repository/org/slf4j/jul-to-slf4j/1.7.21/jul-to-slf4j-1.7.21.jar, file:/Users/example/.m2/repository/org/codehaus/groovy/groovy/2.4.7/groovy-2.4.7.jar, file:/Users/example/.m2/repository/org/hibernate/hibernate-validator/5.2.4.Final/hibernate-validator-5.2.4.Final.jar, file:/Users/example/.m2/repository/org/springframework/boot/spring-boot-starter/1.4.1.BUILD-SNAPSHOT/spring-boot-starter-1.4.1.BUILD-SNAPSHOT.jar, file:/Users/example/.m2/repository/com/fasterxml/classmate/1.3.1/classmate-1.3.1.jar, file:/Users/example/.m2/repository/org/apache/tomcat/embed/tomcat-embed-el/8.5.4/tomcat-embed-el-8.5.4.jar, file:/Users/example/.m2/repository/org/apache/tomcat/embed/tomcat-embed-core/8.5.4/tomcat-embed-core-8.5.4.jar, file:/Users/example/.m2/repository/org/thymeleaf/thymeleaf-spring4/2.1.5.RELEASE/thymeleaf-spring4-2.1.5.RELEASE.jar, file:/Users/example/.m2/repository/org/springframework/spring-context/4.3.2.RELEASE/spring-context-4.3.2.RELEASE.jar, file:/Users/example/.m2/repository/org/thymeleaf/thymeleaf/2.1.5.RELEASE/thymeleaf-2.1.5.RELEASE.jar, file:/Users/example/.m2/repository/nz/net/ultraq/thymeleaf/thymeleaf-layout-dialect/1.4.0/thymeleaf-layout-dialect-1.4.0.jar, file:/Users/example/.m2/repository/org/yaml/snakeyaml/1.17/snakeyaml-1.17.jar, file:/Users/example/.m2/repository/org/springframework/spring-webmvc/4.3.2.RELEASE/spring-webmvc-4.3.2.RELEASE.jar, file:/Users/example/.m2/repository/org/springframework/spring-beans/4.3.2.RELEASE/spring-beans-4.3.2.RELEASE.jar, file:/Users/example/.m2/repository/org/slf4j/slf4j-api/1.7.21/slf4j-api-1.7.21.jar, file:/Users/example/.m2/repository/org/springframework/boot/spring-boot-starter-logging/1.4.1.BUILD-SNAPSHOT/spring-boot-starter-logging-1.4.1.BUILD-SNAPSHOT.jar, file:/Users/example/.m2/repository/com/fasterxml/jackson/core/jackson-annotations/2.8.1/jackson-annotations-2.8.1.jar, file:/Users/example/.m2/repository/ognl/ognl/3.0.8/ognl-3.0.8.jar, file:/Users/example/.m2/repository/org/springframework/boot/spring-boot-starter-thymeleaf/1.4.1.BUILD-SNAPSHOT/spring-boot-starter-thymeleaf-1.4.1.BUILD-SNAPSHOT.jar, file:/Users/example/.m2/repository/org/apache/tomcat/embed/tomcat-embed-websocket/8.5.4/tomcat-embed-websocket-8.5.4.jar, file:/Users/example/.m2/repository/ch/qos/logback/logback-classic/1.1.7/logback-classic-1.1.7.jar, file:/Users/example/.m2/repository/org/springframework/boot/spring-boot-starter-tomcat/1.4.1.BUILD-SNAPSHOT/spring-boot-starter-tomcat-1.4.1.BUILD-SNAPSHOT.jar, file:/Users/example/.m2/repository/org/springframework/spring-expression/4.3.2.RELEASE/spring-expression-4.3.2.RELEASE.jar, file:/Users/example/.m2/repository/ch/qos/logback/logback-core/1.1.7/logback-core-1.1.7.jar, file:/Users/example/.m2/repository/javax/validation/validation-api/1.1.0.Final/validation-api-1.1.0.Final.jar, file:/Users/example/.m2/repository/org/springframework/spring-core/4.3.2.RELEASE/spring-core-4.3.2.RELEASE.jar, file:/Users/example/.m2/repository/com/fasterxml/jackson/core/jackson-databind/2.8.1/jackson-databind-2.8.1.jar, file:/Users/example/.m2/repository/org/springframework/boot/spring-boot-autoconfigure/1.4.1.BUILD-SNAPSHOT/spring-boot-autoconfigure-1.4.1.BUILD-SNAPSHOT.jar, file:/Users/example/.m2/repository/org/slf4j/jcl-over-slf4j/1.7.21/jcl-over-slf4j-1.7.21.jar, file:/Users/example/.m2/repository/org/slf4j/log4j-over-slf4j/1.7.21/log4j-over-slf4j-1.7.21.jar, file:/Users/example/.m2/repository/org/springframework/spring-aop/4.3.2.RELEASE/spring-aop-4.3.2.RELEASE.jar, file:/Users/example/.m2/repository/org/jboss/logging/jboss-logging/3.3.0.Final/jboss-logging-3.3.0.Final.jar, file:/Users/example/.m2/repository/org/springframework/boot/spring-boot-starter-web/1.4.1.BUILD-SNAPSHOT/spring-boot-starter-web-1.4.1.BUILD-SNAPSHOT.jar]
2016-08-02 11:34:54.966 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'context.listener.classes' in any property source
2016-08-02 11:34:54.968 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'banner.image.location' in any property source
2016-08-02 11:34:54.970 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'banner.location' in any property source

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::  (v1.4.1.BUILD-SNAPSHOT)

2016-08-02 11:34:55.013 DEBUG 48156 --- [           main] o.s.w.c.s.StandardServletEnvironment     : Adding [servletConfigInitParams] PropertySource with lowest search precedence
2016-08-02 11:34:55.014 DEBUG 48156 --- [           main] o.s.w.c.s.StandardServletEnvironment     : Adding [servletContextInitParams] PropertySource with lowest search precedence
2016-08-02 11:34:55.014 DEBUG 48156 --- [           main] o.s.w.c.s.StandardServletEnvironment     : Adding [systemProperties] PropertySource with lowest search precedence
2016-08-02 11:34:55.014 DEBUG 48156 --- [           main] o.s.w.c.s.StandardServletEnvironment     : Adding [systemEnvironment] PropertySource with lowest search precedence
2016-08-02 11:34:55.015 DEBUG 48156 --- [           main] o.s.w.c.s.StandardServletEnvironment     : Initialized StandardServletEnvironment with PropertySources [servletConfigInitParams,servletContextInitParams,systemProperties,systemEnvironment]
2016-08-02 11:34:55.046 DEBUG 48156 --- [           main] o.s.c.a.ClassPathBeanDefinitionScanner   : JSR-250 'javax.annotation.ManagedBean' found and supported for component scanning
2016-08-02 11:34:55.049 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'context.initializer.classes' in any property source
2016-08-02 11:34:55.049 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'spring.config.name:application' in any property source
2016-08-02 11:34:55.049 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'spring.config.name' in any property source
2016-08-02 11:34:55.050 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'vcap.application.name:application' in any property source
2016-08-02 11:34:55.050 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'vcap.application.name' in any property source
2016-08-02 11:34:55.050 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'spring.application.name:application' in any property source
2016-08-02 11:34:55.050 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'spring.application.name' in any property source
2016-08-02 11:34:55.051 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'PORT:null' in any property source
2016-08-02 11:34:55.051 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'PORT' in any property source
2016-08-02 11:34:55.051 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'server.port:null' in any property source
2016-08-02 11:34:55.051 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'server.port' in any property source
2016-08-02 11:34:55.051 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'spring.application.index:null' in any property source
2016-08-02 11:34:55.051 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'spring.application.index' in any property source
2016-08-02 11:34:55.052 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'vcap.application.instance_index:null' in any property source
2016-08-02 11:34:55.052 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'vcap.application.instance_index' in any property source
2016-08-02 11:34:55.052 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'spring.profiles.active' in any property source
2016-08-02 11:34:55.061  INFO 48156 --- [           main] sample.web.ui.SampleWebUiApplication     : Starting SampleWebUiApplication on example.local with PID 48156 (/Users/example/github/spring-boot/spring-boot-samples/spring-boot-sample-web-ui/target/classes started by example in /Users/example/github/spring-boot/spring-boot-samples/spring-boot-sample-web-ui)

...

2016-08-02 11:34:58.009 DEBUG 48156 --- [           main] utoConfigurationReportLoggingInitializer :


=========================
AUTO-CONFIGURATION REPORT
=========================


Positive matches:
-----------------

   AbstractThymeleafViewResolverConfiguration#thymeleafViewResolver matched
      - @ConditionalOnMissingBean (names: thymeleafViewResolver; SearchStrategy: all) found no beans (OnBeanCondition)
      - matched (OnPropertyCondition)

   DispatcherServletAutoConfiguration matched
      - @ConditionalOnClass classes found: org.springframework.web.servlet.DispatcherServlet (OnClassCondition)
      - found web application StandardServletEnvironment (OnWebApplicationCondition)

   DispatcherServletAutoConfiguration.DispatcherServletConfiguration matched
      - @ConditionalOnClass classes found: javax.servlet.ServletRegistration (OnClassCondition)
      - no DispatcherServlet found (DispatcherServletAutoConfiguration.DefaultDispatcherServletCondition)

   DispatcherServletAutoConfiguration.DispatcherServletRegistrationConfiguration matched
      - @ConditionalOnClass classes found: javax.servlet.ServletRegistration (OnClassCondition)
      - no ServletRegistrationBean found (DispatcherServletAutoConfiguration.DispatcherServletRegistrationCondition)


...
	

Negative matches:
-----------------

   ActiveMQAutoConfiguration did not match
      - required @ConditionalOnClass classes not found: javax.jms.ConnectionFactory,org.apache.activemq.ActiveMQConnectionFactory (OnClassCondition)

   AopAutoConfiguration did not match
      - required @ConditionalOnClass classes not found: org.aspectj.lang.annotation.Aspect,org.aspectj.lang.reflect.Advice (OnClassCondition)

   ArtemisAutoConfiguration did not match
      - required @ConditionalOnClass classes not found: javax.jms.ConnectionFactory,org.apache.activemq.artemis.jms.client.ActiveMQConnectionFactory (OnClassCondition)


...
	
2016-08-02 11:34:58.015 DEBUG 48156 --- [           main] o.s.w.s.resource.ResourceUrlProvider     : Looking for resource handler mappings
2016-08-02 11:34:58.015 DEBUG 48156 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'resourceHandlerMapping'
2016-08-02 11:34:58.016 DEBUG 48156 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'faviconHandlerMapping'
2016-08-02 11:34:58.016 DEBUG 48156 --- [           main] o.s.w.s.resource.ResourceUrlProvider     : Found resource handler mapping: URL pattern="/**/favicon.ico", locations=[ServletContext resource [/], class path resource [META-INF/resources/], class path resource [resources/], class path resource [static/], class path resource [public/], class path resource []], resolvers=[org.springframework.web.servlet.resource.PathResourceResolver@1a0d049e]
2016-08-02 11:34:58.016 DEBUG 48156 --- [           main] o.s.w.s.resource.ResourceUrlProvider     : Found resource handler mapping: URL pattern="/webjars/**", locations=[class path resource [META-INF/resources/webjars/]], resolvers=[org.springframework.web.servlet.resource.PathResourceResolver@1654f32]
2016-08-02 11:34:58.016 DEBUG 48156 --- [           main] o.s.w.s.resource.ResourceUrlProvider     : Found resource handler mapping: URL pattern="/**", locations=[ServletContext resource [/], class path resource [META-INF/resources/], class path resource [resources/], class path resource [static/], class path resource [public/]], resolvers=[org.springframework.web.servlet.resource.PathResourceResolver@3c808a1b]
2016-08-02 11:34:58.017 DEBUG 48156 --- [           main] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'spring.liveBeansView.mbeanDomain' in any property source
2016-08-02 11:34:58.061  INFO 48156 --- [           main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat started on port(s): 8080 (http)
2016-08-02 11:34:58.062 DEBUG 48156 --- [           main] o.s.w.c.s.StandardServletEnvironment     : Adding [server.ports] PropertySource with highest search precedence
2016-08-02 11:34:58.065  INFO 48156 --- [           main] sample.web.ui.SampleWebUiApplication     : Started SampleWebUiApplication in 3.393 seconds (JVM running for 6.41)

tl;dr

tl;dr

I know. Nobody wants to read all of this output. So let me highlight some of the best parts:

  • ClasspathLoggingApplicationListener – Complete paths and jar files in your classpath.
  • PropertySourcesPropertyResolver – Properties files and property keys that Spring is hoping to find.
  • ClassPathBeanDefinitionScanner – Beans found on your classpath that support component scanning.
  • PathMatchingResourcePatternResolver – Locations in your classpath where resources are expected.
  • ConfigurationClassBeanDefinitionReader – Beans that are registered by a Configuration class.
  • ConfigurationClassEnhancer – Beans that are “enhanced” or augmented dynamically by CGLIB.
  • DefaultListableBeanFactory – Beans that are registered with Spring, autowired beans, caching, singletons, and circular references.
  • RequestMappingHandlerMapping – Mapping of bean requests to methods.
  • BeanNameUrlHandlerMapping – Beans that could not be found.
  • AutoConfigurationReportLoggingInitializer – A verbose report of what Spring Boot did and didn’t find. (Very useful)

There’s more here that you can read and interpret at your own pace, but I wanted to quickly illustrate how much information was available with just a tweak to your logback.xml file. When your application isn’t loading, or isn’t functioning as expected, the exact reasons are likely to be here.