others-how to customize your logging format for springboot kotlin project?
1. Purpose
In this post, I will show you how to customize your logging format for springboot or java project that is uing logback, and I will also show you how to output custom field using MDC.
2. Logging pattern
Open your project’s src/main/resources/logback-spring.xml, if you want output logs to console , you can define as follows:
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<include resource="org/springframework/boot/logging/logback/defaults.xml"/>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>
%d{dd-MM-yyyy HH:mm:ss.SSS} %magenta([%-15.15thread]) %highlight(%-5level) %yellow(%-40.40C{40}) - %msg%n%throwable
</pattern>
</encoder>
</appender>
<root level="INFO">
<appender-ref ref="STDOUT" />
</root>
</configuration>
Logback classic ships with a flexible layout called PatternLayout. As all layouts, PatternLayout takes a logging event and returns a String. However, this String can be customized by tweaking PatternLayout’s conversion pattern, The conversion pattern of PatternLayout is closely related to the conversion pattern of the printf() function in the C programming language. A conversion pattern is composed of literal text and format control expressions called conversion specifiers. You are free to insert any literal text within the conversion pattern. Each conversion specifier starts with a percent sign ‘%’ and is followed by optional format modifiers, a conversion word and optional parameters between braces. The conversion word controls the data field to convert, e.g. logger name, level, date or thread name. The format modifiers control field width, padding, and left or right justification.
Some explanations on the above example log appender’s pattern:
- %d{pattern}: Used to output the date of the logging event. The date conversion word admits a pattern string as a parameter. The pattern syntax is compatible with the format accepted by java.text.SimpleDateFormat (in logback 1.2.x) and java.time.format.DateTimeFormatter (in logback 1.3.x). For example:
- %d: output
2006-10-20 14:06:49,812 - %date{HH:mm:ss.SSS}: output
14:06:49.812
- %d: output
- %magenta: Specify the text color
- %thread: Outputs the name of the thread that generated the logging event.
- %msg: Outputs the application-supplied message associated with the logging event.
- %n: Outputs the platform dependent line separator character or characters.
- %throwable: Outputs the stack trace of the exception associated with the logging event, if any. By default the full stack trace will be output.
Now we can add a logger object in our code(A kotlin controller):
package com.example.controllers
import com.example.domain.Message
import org.slf4j.Logger
import org.slf4j.LoggerFactory
import org.springframework.web.bind.annotation.GetMapping
import org.springframework.web.bind.annotation.RestController
@RestController
class MessageController {
val Any.logger: Logger
get() = LoggerFactory.getLogger(this.javaClass)
@GetMapping
fun index(): List<Message> {
logger.info("got list request")
var result = listOf(
Message("1","hello1"),
Message("2","Object"),
Message("3","Privot"),
)
return result
}
}
got this result:
08-12-2022 17:32:13.167 [nio-8081-exec-1] INFO c.example.controllers.MessageController - got list request
And if you want to output logs to files, you can do as follows:
<configuration>
<timestamp key="byHour" datePattern="yyyyMMdd'T'HH"/>
<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<file>log-${bySecond}.log</file>
<append>true</append>
<!-- set immediateFlush to false for much higher logging throughput -->
<immediateFlush>true</immediateFlush>
<!-- encoders are assigned the type
ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
<encoder>
<pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
</encoder>
</appender>
<root level="DEBUG">
<appender-ref ref="FILE" />
</root>
</configuration>
In the above pattern, there are some specical patterns:
- %relative: Outputs the number of milliseconds elapsed since the start of the application until the creation of the logging event.
- %logger: Outputs the name of the logger at the origin of the logging event.This conversion word takes an integer as its first and only option. The converter’s abbreviation algorithm will shorten the logger name, usually without significant loss of meaning. Setting the value of length option to zero constitutes an exception. It will cause the conversion word to return the sub-string right to the rightmost dot character in the logger name. The next table provides examples of the abbreviation algorithm in action. For example:
- %logger in class
mainPackage.sub.sample.Bar, will outputmainPackage.sub.sample.Bar - %logger{10} in class
mainPackage.sub.sample.Bar, will outputm.s.s.Bar
- %logger in class
And if you want a rolling file logger appender, you can do as follows:
<appender name="errorAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>logs/error.log</file>
<!-- set Rolling policy: TimeBasedRollingPolicy roll by date -->
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<!--set file name pattern-->
<fileNamePattern>errorFile.%d{yyyy-MM-dd}.log</fileNamePattern>
<!--set the max retain days-->
<maxHistory>30</maxHistory>
</rollingPolicy>
<!-- if exceed 100M, then trigger a new rolling file -->
<triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
<maxFileSize>100</maxFileSize>
</triggeringPolicy>
<encoder>
<pattern>%d [%p] %-5level %logger - %msg%newline</pattern>
</encoder>
</appender>
3. Add custom fields to log appender
We can use MDC to implement custom fileds in logback.
The full name of MDC is Mapped Diagnostic Context, which can be roughly understood as a thread-safe container for storing diagnostic logs.
Here is a simple example of MDC:
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import java.util.UUID;
/**
* MDC quick start
*/
public class QuickStartOfMDC {
private static final Logger logger = LoggerFactory.getLogger(QuickStartOfMDC.class);
public static final String REQ_ID = "REQ_ID";
public static void main(String[] args) {
MDC.put(REQ_ID, UUID.randomUUID().toString());
logger.info("Start doing job A...");
logger.info("Job A is done");
MDC.remove(REQ_ID);
logger.info("REQ_ID removed? {}", MDC.get(REQ_ID) != null);
}
}
You can see that we are just calling MDC.put and MDC.remove , we do nothing else, we now need to add MDC custom field REQ_ID to our logger appender:
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<layout class="ch.qos.logback.classic.PatternLayout">
<Pattern>[%t] [%X{REQ_ID}] - %m%n</Pattern>
</layout>
</appender>
<root level="debug">
<appender-ref ref="CONSOLE"/>
</root>
</configuration>
You can see that we use the pattern: %X{REQ_ID} to print our custom field implemented by MDC.
Running the app, we out such logs:
[1212122-1212-abcd-1223-022xaskdfjlkdje] - Start doing job A...
[1212122-1212-abcd-1223-022xaskdfjlkdje] - Job A is done
You can see that the logs contain our custom field REQ_ID put by MDC, so we can use MDC to output some useful information.
And because MDC uses ThreadLocal, and ConcurrentSynchronizedMap, it’s thread safe in multiple threads environment.
So we can conclude:
a) The put method provided by MDC can put a KV key-value pair into the container, and can ensure that the Key is unique in the same thread, and the MDC values of different threads do not affect each other
b) In logback.xml, you can output the information of REQ_ID in MDC by declaring %X{REQ_ID} in the layout
c) The remove method provided by MDC can clear the key-value pair information corresponding to the specified key in MDC
4. Summary
In this post, I demonstrated how to customize your logging format for springboot kotlin project , and I still show you how to use MDC to implement a custom logging field. That’s it, thanks for your reading.