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,DEBUGorTRACE. - 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= trueapplication.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= trueapplication.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:
| 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:
- 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 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.
You can download the source code of this example here: spring-boot-logging.zip.
