Java Logging Part 4: Introduction to Logback

By Shangzuo

1. Configure the Entry

Logback supports XML and Groovy configuration. In terms of XML, it will find logback-test.xml (for testing)/ logback.xml files in the resources directory by default.

And if you use Spring Boot, then you can also use logback-spring.xml files to configure. The difference between the two is:

• The logback-spring.xml is found by Spring Boot, inserted into its own context information [1], and passed to Logback after further processing. You can use <springProfile> to distinguish environment configuration in it, or you can use <springProperty> to get Spring context information (such as spring.application.name).

• The logback.xml is found by Logback itself, which naturally does not have Spring Boot-related capabilities.

2. Introduction to Configuration Files

Next, we will take logback-spring.xml as an example. A Logback configuration file has the following tags:

• confinuration: The outermost parent tag. There are several attribute configurations, but it is less used in the project. Therefore, we will not talk too much about it.

• property: Defining variables.

• appender: It is responsible for log output (usually written to files), through which we can set the output scheme.

• logger: It is used to set the print level of a LoggerName.

• root: logger bottom-line configuration. With it, we don't have to configure each LoggerName.

• conversionRule: It defines a conversion rule. For more information, please refer to section 4. Java API.

2.1 springProperty and property

As mentioned earlier, the <springProperty> is used to insert Spring context. Then the <property> is the label of the variable defined by Logback itself. Look directly at the example:

<springProperty scope="context" name="APP_NAME" source="spring.application.name"/>

<property name="LOG_PATH" value="${user.home}/${APP_NAME}/logs"/>
<property name="APP_LOG_FILE" value="${LOG_PATH}/application.log"/>
<property name="APP_LOG_PATTERN"
          value="%date{yyyy-MM-dd HH:mm:ss.SSS}|%-5level|%X{trace_id}|%thread|%logger{20}|%message%n%exception"/>

We first use <springProperty> to insert the APP_NAME variable to represent the application name, and then use it to construct the LOG_PATH variable. The example also uses the context variable [2] ${user.home}, the built-in support of Logback. APP_LOG_FILE is the log file path. APP_LOG_PATTERN is the log format (please refer to section 3. Placeholder).

2.2 appender

There are many key points involved in this section. First, look at an example directly:

<appender name="APPLICATION" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${APP_LOG_FILE}</file>
    <encoder>
        <pattern>${APP_LOG_PATTERN}</pattern>
    </encoder>
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
        <fileNamePattern>${APP_LOG_FILE}.%d{yyyy-MM-dd}.%i</fileNamePattern>
        <maxHistory>30</maxHistory>
        <maxFileSize>200MB</maxFileSize>
        <totalSizeCap>10GB</totalSizeCap>
    </rollingPolicy>
</appender>
<appender name="APPLICATION-async" class="ch.qos.logback.classic.AsyncAppender">
    <queueSize>256</queueSize>
    <discardingThreshold>0</discardingThreshold>
    <neverBlock>true</neverBlock>
    <appender-ref ref="APPLICATION"/>
</appender>

The variables involved in the example were mentioned in the previous section, so I won't talk about them here. Please pay attention to the following points:

• The ch.qos.logback.core.rolling.RollingFileAppender is responsible for rolling log printing to avoid the expanding size of a single file. The specific rolling strategy is specified in the <rollingPolicy>, and each configuration item is quite easy to understand.

• The ch.qos.logback.classic.AsyncAppender is responsible for printing logs asynchronously to avoid blocking threads when printing a large number of logs.

In addition to the above two, if the ch.qos.logback.core.ConsoleAppender is used to output logs to the console. If you use it, it is recommended to refer to the section [Part nine, Do not Output Logs to the Console]. For more information about Appender and RollingPolicy, please refer to Chapter 4: Appenders of the official document [3].

2.3 logger and root

<logger> is used to set the print level for a LoggerName. For example:

<logger level="INFO" additivity="false" name="com.foo.bar">
    <appender-ref ref="APPLICATION-async"/>
</logger>
<root level="INFO">
    <appender-ref ref="APPLICATION-async"/>
</root>

The above configuration specifies that all logs with LoggerName com.foo.bar are printed at the INFO level (the TRACE and DEBUG levels will not be output), and the output (appender) bound to this configuration is APPLICATION-async.

LoggerName will end with . For example, if the actual LoggerName is com.foo.bar.service.ExampleService, the search process is as follows:

com.foo.bar.service.ExampleService
com.foo.bar.service
com.foo.bar (the <logger> in our example is hit at this time, and the downward search is stopped because additivity="false" is configured)
com.foo
com
<root>

The <root> is the bottom configuration. When LoggerName does not match any <logger>, <root> will be used, so it has no additivity and name attributes.

In actual business scenarios, we recommend that you add additivity="false" to all <logger>. Otherwise, multiple logs will be printed due to multiple <logger> (or <root>).

2.4 springProfile

Spring also provides <springProfile> tag to dynamically adjust logs based on Spring Profiles 4.

For example, we want the online environment to use the INFO level, while the pre-release and daily use the TRACE level:

<springProfile name="production">
    <root level="INFO">
        <appender-ref ref="APPLICATION-async"/>
    </root>
</springProfile>
<springProfile name="staging,testing">
    <root level="TRACE">
        <appender-ref ref="APPLICATION-async"/>
    </root>
</springProfile>

3. Placeholder

3.1 Conversion Word

Logback provides a large number of useful placeholders for everyone to use. The official documentation is in Conversion Word [5].

For example, some commonly used placeholders (most placeholders have abbreviations, such as %logger can be abbreviated as %c, I will not list them here, please see the official documents given above for details):

Placeholder	Description
`%logger`	Output LoggerName (see section Part 3: 1.1 Factory Functions).
`%message`	Output the log you actually want to print (see section Part 3: 3.1 info Method).
`%exception`	Output the exception stack, which corresponds to the exception passed through Slf4j (see section Part 3: 3.1 info Method).
`%level`	Output log level, i.e. `TRACE` / `DEBUG` / `INFO` / `WARN` / `ERROR` / `FATAL`. Note that this is different from Slf4j (see section Part 3: 2. Log Level), there is an additional `FATAL` level, which exists to adapt to Log4j.
`%xException`	Output the exception stack contains the name of the JAR package to which each row of the stack belongs.
`%marker`	Output the string passed in by Marker (see section Part 3: 4. Marker).
`%mdc`	Output the corresponding value in MDC (see section Part 3: 5. MDC).
`%kvp`	Output the KV pair passed through the `addKeyValue` (see section Part 3: 6. Fluent API (Chain Call)).
`%date`	Output time, you can add ISO 8601[6] parameters to specify the output format, such as our commonly used `yyyy-MM-dd HH:mm:ss`.
`%thread`	Output the name of the thread where the printed log method is located.
`%n`	Output a line break.
`%replace(p){r, t}`	Replace r in p with t, and r is regular. Please refer to section [Part 5: 7. Merge Stacks into One Line]
`%nopex`	The incoming stack is ignored and not printed. Please refer to section [Part 5: 7. Merge Stacks into One Line]. Logback will judge your log pattern. If there is no output stack, `%exception` will be appended by default to ensure that the incoming exception information will not be lost. This placeholder is an explicit request not to append.

In addition, there is a supplement to %logger. You can set the %logger parameter to a positive integer that specifies the length of the output. If the length of the LoggerName parameter exceeds the limit, Logback automatically shortens the length of the Logback parameter with a (.). Assuming LoggerName is com.example.foo.bar.ExampleService (this string length is 34), then:

Configuration	Output result	Description
`[%logger]`	`[com.example.foo.bar.ExampleService]`	Reserved columns.
`[%logger{32}]`	`[c.example.foo.bar.ExampleService]`	The actual length is 32, consistent with the limit value.
`[%logger{30}]`	`[c.e.foo.bar.ExampleService]`	The actual length is 26, smaller than the limit value. Each level of the package is either kept as is or only the first character is used.
`[%logger{10}]`	`[c.e.f.b.ExampleService]`	The actual length is 20, greater than the limit value. Each level of the package will retain at least one character, and the last level will not be shortened.
`[%logger{0}]`	`[ExampleService]`	The 0 is special, indicating that only the last level is retained and will not be shortened.

3.2 Format Modifiers

As we can see from the previous content, the basic usage of placeholders is % placeholder {parameter}. However, there is an optional configuration that can be placed between % and placeholders, called Format modifiers[7]. A complete format configuration contains five parts, such as: -10.-20, we will explain respectively:

• -: The first-parameter indicates that spaces are padded on the right side when the minimum length is insufficient. This means that the output content is aligned to the left. By default, spaces are padded on the left side, which is aligned to the right.

• 10: The first number indicates the minimum length of the output and the insufficient complement space;

• .: The delimiter that is used to separate the two items that follow it. It has no meaning by itself.

• -: The second - value indicates that the characters on the right side are cropped first, that is, the characters on the left side are retained. By default, the characters on the left side are clipped first, that is, the characters on the right side are retained.

• 20: The second number indicates the maximum length of the output, and the excess part will be cropped.

For examples:

Configuration	Text	Output result	Description
`[%5level]`	`INFO`	`[ INFO]`	A minimum of 5 characters, right-aligned.
`[%-5level]`	`INFO`	`[INFO ]`	A minimum of 5 characters, left-aligned.
`[%.-1level]`	`INFO`	`[I]`	A maximum of 1 character. The characters on the left side are reserved first.
`[%-5,-10logger]`	`com.foo.bar.Service`	`[com.foo.ba]`	A maximum of 10 characters. The characters on the left side are reserved first.
`[%-5,10logger]`	`com.foo.bar.Service`	`[ar.Service]`	A maximum of 10 characters. The characters on the right side are reserved first.

4. Java API

In addition to using XML configuration files, Logback provides a number of Java APIs [8] to support more complex business demands. Let's briefly introduce it through three very practical scenarios.

Scenario 1: How to convert obj into JSON String for output when using log.info("obj={}", obj).
Scenario 2: How to de-identify the mobile phone number and ID number involved in the log and then record the log.
Scenario 3: The Logback configuration is based on XML. You can also dynamically modify the log level without changing the code or publishing.

The first two of these issues can be achieved through the MessageConverter [9], because of space limitation, you can refer to the subsequent articles for specific introduction.

The third issue can be achieved through the LoggerContext [10] and Logger [11]. Also for space limitation, you can refer to the subsequent articles for specific introduction.

5. TraceId in MDC

I take out a separate section to talk about this because I find that many people are prone to manually record traceId, such as:

log.info("traceId={}, blah blah blah", Span.current().getSpanContext().getTraceId());

In fact, OpenTelemetry [12] has automatically added traceId to MDC, and the corresponding Key is trace_id. Use %mdc{trace_id} (see Part 3, section 5. MDC) to print traceId. For example, we use this key in the example in the section 2.1 springProperty and property.

6. Summary

The above is just a brief introduction to the common functions of Logback. For more information, see the official document Logback documentation [13]. In particular, many of these examples are introduced together with Slf4j, which is very easy to understand.