Boot

Spring Boot Logging Example

Looking to learn about Spring Boot Logging? Read this example, it is very straight forward and simple.

1. Assumptions

This article assumes that you know your way around Eclipse. You are familiar with Maven. This project has been created using Eclipse Mars so all instructions are based on this IDE. This article uses the code base from the Spring Boot JDBC Example article.
 
 
 

2. Introduction

Spring Boot provides logging support right out of the box. Spring Boot uses Commons Logging for internal logging. Default configurations are provided for Java Util Logging, Log4J and Logback. Spring Boot logging is pre-configured to use console output. When we run our example code, we will see something like below (ellipses added to shorten the output):

Console Output

...
2018-02-03 15:14:31.428  INFO 8628 --- [           main] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@6fb0d3ed: startup date [Sat Feb 03 15:14:31 GMT 2018]; root of context hierarchy
2018-02-03 15:14:38.466  INFO 8628 --- [           main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
...
2018-02-03 15:14:41.121  INFO 8628 --- [       Thread-2] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@6fb0d3ed: startup date [Sat Feb 03 15:14:31 GMT 2018]; root of context hierarchy
2018-02-03 15:14:41.158  INFO 8628 --- [       Thread-2] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown

Logging was enabled because we used a Spring “starter” module. All “starters” depend on spring-boot-starter-logging. Logback is used in “starters”. In our example, we used spring-boot-starter-jdbc.

Default Format

  • Date and Time – Millisecond precision and easily sortable.
  • Log Level – ERROR, WARN, INFO, DEBUG or TRACE.
  • Process ID.
  • A “—” separator to distinguish the start of actual log messages.
  • Thread – Enclosed in square brackets (may be truncated for console output).
  • Logger – This is usually the source class name (often abbreviated).
  • The log message.

3. Debug and Trace Mode

By default ERROR, WARN and INFO level messages are logged. You can also enable a “debug” mode by starting your application with a --debug flag.

Debug Mode Command

$ java -jar spring-boot-logging-0.0.1-SNAPSHOT.jar --debug

To create the jar: mvn package. The jar file is saved in the target directory

Setting the debug mode through a properties file or yml file.

  • application.properties: debug= true
  • application.yml: debug: true

The debug mode log looks like the one below. Ellipses have been added to shorten the log.

Debug Log

2018-02-03 16:19:36.741 DEBUG 5784 --- [           main] .b.l.ClasspathLoggingApplicationListener : Application started with classpath: [jar:file:...]
...
2018-02-03 16:19:37.961  INFO 5784 --- [           main] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@6e5e91e4: startup date [Sat Feb 03 16:19:37 GMT 2018]; root of context hierarchy
2018-02-03 16:19:43.083  INFO 5784 --- [           main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2018-02-03 16:19:43.184 DEBUG 5784 --- [           main] utoConfigurationReportLoggingInitializer : 

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

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

   DataSourceAutoConfiguration matched:
      - @ConditionalOnClass found required classes 'javax.sql.DataSource', 'org.springframework.jdbc.datasource.embedded.EmbeddedDatabaseType'; @ConditionalOnMissingClass did not find unwanted class (OnClassCondition)
...

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

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

Exclusions:
-----------

    None

Unconditional classes:
----------------------

    org.springframework.boot.autoconfigure.context.ConfigurationPropertiesAutoConfiguration

...
2018-02-03 16:19:44.546  INFO 5784 --- [       Thread-2] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@6e5e91e4: startup date [Sat Feb 03 16:19:37 GMT 2018]; root of context hierarchy
2018-02-03 16:19:44.550  INFO 5784 --- [       Thread-2] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown

Enabling trace mode is the same as enabling debug mode.

Trace Mode Command

$ java -jar spring-boot-logging-0.0.1-SNAPSHOT.jar --trace

Setting the trace mode through a properties file or yml file.

  • application.properties: trace= true
  • application.yml: trace: true

The trace mode log looks like the one below. Ellipses have been added to shorten the log.

Trace Mode Command

2018-02-03 16:35:12.178 DEBUG 8052 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Creating instance of bean 'org.springframework.boot.autoconfigure.jdbc.DataSourceTransactionManagerAutoConfiguration'
2018-02-03 16:35:12.179 DEBUG 8052 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Eagerly caching bean 'org.springframework.boot.autoconfigure.jdbc.DataSourceTransactionManagerAutoConfiguration' to allow for resolving potential circular references
2018-02-03 16:35:12.179 TRACE 8052 --- [           main] o.s.beans.CachedIntrospectionResults     : Getting BeanInfo for class [org.springframework.boot.autoconfigure.jdbc.DataSourceTransactionManagerAutoConfiguration$EnhancerBySpringCGLIB$c5f63ccb]
...
2018-02-03 16:35:12.547 TRACE 8052 --- [           main] s.c.a.AnnotationConfigApplicationContext : Publishing event in org.springframework.context.annotation.AnnotationConfigApplicationContext@8e0379d: org.springframework.context.event.ContextRefreshedEvent; root of context hierarchy]
2018-02-03 16:35:12.551 DEBUG 8052 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'org.springframework.boot.autoconfigure.internalCachingMetadataReaderFactory'
2018-02-03 16:35:12.552 DEBUG 8052 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'org.springframework.boot.context.properties.ConfigurationPropertiesBindingPostProcessor'

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

...
2018-02-03 16:35:12.675 DEBUG 8052 --- [           main] o.s.jdbc.core.JdbcTemplate               : Executing SQL statement [DROP TABLE movies IF EXISTS]
2018-02-03 16:35:12.704 DEBUG 8052 --- [           main] o.s.jdbc.datasource.DataSourceUtils      : Fetching JDBC Connection from DataSource
2018-02-03 16:35:12.765 DEBUG 8052 --- [           main] o.a.tomcat.jdbc.pool.PooledConnection    : Instantiating driver using class: org.h2.Driver [url=jdbc:h2:mem:testdb;DB_CLOSE_DELAY=-1;DB_CLOSE_ON_EXIT=FALSE]
...
2018-02-03 16:35:13.650 TRACE 8052 --- [           main] o.s.jdbc.core.StatementCreatorUtils      : Setting SQL statement parameter value: column index 2, parameter value [Comedy], value class [java.lang.String], SQL type unknown
2018-02-03 16:35:13.656 DEBUG 8052 --- [           main] o.s.jdbc.core.JdbcTemplate               : SQL update affected 1 rows
2018-02-03 16:35:13.658 DEBUG 8052 --- [           main] o.s.jdbc.datasource.DataSourceUtils      : Returning JDBC Connection to DataSource
...
2018-02-03 16:35:13.779 DEBUG 8052 --- [       Thread-2] o.s.b.f.support.DisposableBeanAdapter    : Invoking destroy method 'close' on bean with name 'dataSource'
2018-02-03 16:35:13.788 DEBUG 8052 --- [       Thread-2] o.s.b.f.support.DisposableBeanAdapter    : Invoking destroy() on bean with name 'org.springframework.boot.context.properties.ConfigurationPropertiesBindingPostProcessor'
2018-02-03 16:35:13.788 DEBUG 8052 --- [       Thread-2] o.s.b.f.s.DefaultListableBeanFactory     : Retrieved dependent beans for bean 'org.springframework.boot.autoconfigure.internalCachingMetadataReaderFactory': [org.springframework.context.annotation.internalConfigurationAnnotationProcessor]

4. Log with Color

Colors are used to convey information. Color-coded logging is supported for ANSI terminals.

application.properties

spring.output.ansi.enabled= ALWAYS

application.yml

spring:
  output:
    ansi:
      enabled: ALWAYS

Supported ANSI values:

  • ALWAYS – Enable ANSI-colored output.
  • DETECT – Try to detect whether ANSI coloring capabilities are available.
  • NEVER – Disable ANSI-colored output.

The default color coding according to log level are as follows:

LevelColor
FATAL, ERRORRed
WARNYellow
INFO, DEBUG, TRACEGreen

We can change the color coding using the %clr corversion word. Example: %clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){yellow}

The supported colors are:

  • blue
  • cyan
  • faint
  • green
  • magenta
  • red
  • yellow

5. Log To A File

We set the logging.file or the logging.path property to enable file logging. Log files will rotate when they reach 10MB. Example:

application.properties

logging.file = main.log
logging.path = log

application.yml

logging:
  file: main.log
  path: log

If we chose to set the path then we will find spring.log in the log directory. If we specify a file then we should have a main.log in the current working directory.

6. Logging Specific Levels

We can set specific logging according to a log level by using the syntax logging.level.*= LEVEL. LEVEL can be any of the following: TRACE, DEBUG, INFO, WARN, ERROR, FATAL, OFF. The * can be root or a package name. Example:

application.properties

logging.level.root=WARN
logging.level.org.springframework.web=DEBUG

The above example will output debug logging for the org.springframework.web package and will output WARN logging for the entire application.

7. No Logging

We can also disable logging as seen in the example below.

application.yml

logging:
  level:
    root: OFF
    org:
      springframework:
        boot: OFF
        
spring:
  main:
    banner-mode: 'OFF'

8. Log Pattern

application.properties

logging.pattern.console=%date{dd MMM yyyy;HH:mm:ss.SSS} %level = %line: %logger{20} - %msg%n
logging.pattern.file=%-30(%d{HH:mm:ss.SSS} [%thread]) %-5level %logger{32} - %msg%n
Conversion WordEffect
date or dUsed to output the date of the logging event.
levelOutputs the level of the logging event.
lineOutputs the line number from where the logging request was issued.
loggerOutputs the name of the logger at the origin of the logging event.
msgOutputs the application-supplied message associated with the logging event.
threadOutputs the name of the thread that generated the logging event.

-30 right pads whitespace to the output of the sub-pattern (%d{HH:mm:ss.SSS} [%thread]). Level is also right padded if it doesn’t reach 5 characters. This makes the log file easy to read because of the well formatted columns.

With Right Padding

15:45:26.616 [main]            INFO  o.s.c.a.AnnotationConfigApplicationContext - Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@11dc3715: startup date [Sun Feb 04 15:45:26 GMT 2018]; root of context hierarchy
15:45:29.181 [main]            INFO  o.s.j.e.a.AnnotationMBeanExporter - Registering beans for JMX exposure on startup

Without Right Padding

15:46:23.652 [main] INFO o.s.c.a.AnnotationConfigApplicationContext - Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@11dc3715: startup date [Sun Feb 04 15:46:23 GMT 2018]; root of context hierarchy
15:46:26.016 [main] INFO o.s.j.e.a.AnnotationMBeanExporter - Registering beans for JMX exposure on startup

9. Spring Boot Logging Summary

In this example, we have learned the many ways we can configure the logging of our Spring Boot application. We can change the patterns, disable logging, enable more logging information, pretty print the logging information, send the logging output to a file, and many more.

10. Download the Source Code

This is an example about Spring Boot Logging.

Download
You can download the source code of this example here: spring-boot-logging.zip.

Joel Patrick Llosa

I graduated from Silliman University in Dumaguete City with a degree in Bachelor of Science in Business Computer Application. I have contributed to many Java related projects at Neural Technologies Ltd., University of Southampton (iSolutions), Predictive Technologies, LLC., Confluence Service, North Concepts, Inc., NEC Telecom Software Philippines, Inc., and NEC Technologies Philippines, Inc. You can also find me in Upwork freelancing as a Java Developer.
Subscribe
Notify of
guest

This site uses Akismet to reduce spam. Learn how your comment data is processed.

0 Comments
Inline Feedbacks
View all comments
Back to top button