Spring Boot Logging Example (original) (raw)

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

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.

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.

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:

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

Level Color
FATAL, ERROR Red
WARN Yellow
INFO, DEBUG, TRACE Green

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:

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 Word Effect
date or d Used to output the date of the logging event.
level Outputs the level of the logging event.
line Outputs the line number from where the logging request was issued.
logger Outputs the name of the logger at the origin of the logging event.
msg Outputs the application-supplied message associated with the logging event.
thread Outputs 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.

Photo of 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.