In a nutshell: After logback implements the basic log to file function, there are other advanced requirements in enterprise practice. This article describes the advanced use of logback.

1. The introduction

The previous article springBoot + LogBack Log Output Enterprise Practice (part 1) describes how to use and configure logback, and how to output logs to independent files by log level. In enterprise practice, however, there are other requirements, such as the need to use different log levels in multiple environments, how to deal with low log output performance, and how to track request logs in distributed systems. This article explains how to implement these requirements. The details are as follows:

Use asynchronous log output to improve performance
Logback Select a log level in multiple environments
Use MDC to track requests in distributed systems

If you want to see the source code, this paper sample address: https://github.com/mianshenglee/my-example/tree/master/springboot-logback-demo

2. Output logBack status data

The logback documentation states that it is strongly recommended to enable the output of logback status data, which will greatly help us diagnose logback-related problems. The status data allows you to know how the Logback configuration file is loaded, which appenders are configured, and how the Logger is loaded. There are two ways to enable status data output:

Set the properties in the root element (Configuration)debug="true"
Add the element (statusListener) used by the classOnConsoleStatusListener. As follows:

<! Output logback status data -->
<statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener" />
Copy the code

Note that you can choose either of the two. Debug is used to output status data, regardless of the log level in the configuration file.

In this example, the second method is used (adding the statusListener element), and when added, the output looks like this:

3. Logback Generates logs asynchronously

3.1 Asynchronous Output Configuration

According to the previous Logback configuration, the output of logs to files is synchronized. That is, each output of logs is directly written to disk files, which blocks logs and causes unnecessary performance loss. Of course, for general applications, the impact is small, but for high-concurrency applications, performance optimization is necessary. Logback provides AsyncAppender for asynchronous log output. Writing logs asynchronously is as simple as adding an appender based on writing logs asynchronously and pointing to the configured appender. See the following configuration:

<! -- Asynchronous output -->
<appender name="ASYNCDEBUG" class="ch.qos.logback.classic.AsyncAppender">
    <! TRACT, DEBUG, and INFO logs will be discarded if 80% of the queue is full.
    <discardingThreshold>0</discardingThreshold>
    <! Change the default queue depth, which affects performance. The default is 256 -->
    <queueSize>1024</queueSize>
    <! Add additional appenders, one at most -->
    <appender-ref ref="DEBUGFILE"/>
    <includeCallerData>true</includeCallerData>
</appender>//WARN WARN WARN WARN WARN WARN<! -- Asynchronous output associated with root -->
<root level="DEBUG">
    <appender-ref ref="STDOUT"/>
    <appender-ref ref="ASYNCDEBUG" />. / / a little</root>
Copy the code

The following parameters need to be set for AsyncAppender:

The property name	type	describe
queueSize	`int`	Maximum size of a queue. Default is 256
discardingThreshold	`int`	By default, logs of TRACE, DEBUG, and INFO levels are discarded when 20% of the queue capacity is left. Only LOGS of WARN and ERROR levels are retained. To keep all events, set it to 0
includeCallerData	`boolean`	Getting the caller’s data is relatively expensive. To improve performance, caller information is not retrieved by default. By default, only things like thread name orMDCThis “cheap” data is copied. When set to true, the appender contains information about the caller
maxFlushTime	`int`	Depending on the depth and latency of the appender queue being referenced,`AsyncAppender`It can take a long time to refresh the queue. when`LoggerContext`When stopped,`AsyncAppender stop`The method waits for the time specified by the worker thread to complete. Use maxFlushTime to specify the maximum flush time in milliseconds. Events that are not processed within the specified time are discarded. The value of this attribute has the same meaning asThread.join(long)The same
neverBlock	`boolean`	The default is false and the appender blocks rather than discarding information when the queue is full. Set to true, the appender will not block your application and will discard messages

3.2 Principle of Asynchronous Output

AsyncAppender is implemented by blocking the BlockingQueue to avoid logging directly to a file. Instead, it prints the log event to the BlockingQueue and then starts a new worker thread. The main thread is not blocked. The worker thread obtains the logs to be written from the queue and outputs them asynchronously to the corresponding location.

4. Configure Logback in a SpringBoot multi-environment

Application development with SpringBoot supports configuration of multiple environments. Simply add a configuration file in application-*. Properties format and specify the environment using Spring.profiles. active. Also, log output, typically in a development environment, uses the DEBUG level to check for problems, while in a production environment, only ERROR level logs are output. The profile defines the development environment as dev and the production environment as PROd, as shown below:

<! -- Development environment: Debug level -->
<springProfile name="dev">
    <root level="DEBUG">
        <appender-ref ref="STDOUT"/>. / / a little</root>
</springProfile>

<! -- Production environment: Error -->
<springProfile name="prod">
    <root level="INFO">
        <appender-ref ref="STDOUT"/>. / / a little</root>
</springProfile>
Copy the code

The above configuration is set for root (of course, other elements can also be used). After this setting, the decision to use the specified log level output is made based on spring.profiles. Active.

In fact, logback also supports the use of if elements, using if-then-else forms, in conjunction with the condition attribute for condition processing. If you are interested, you can refer to the official document “Conditional Processing of Configuration Files”

5. The MDC distributed application traces requests

When developing distributed applications with SpringBoot, many are microservitized, and when a request comes in, you may need to invoke multiple services to complete the request. When you query logs, especially when the number of requests is large, it is difficult to find logs corresponding to requests. As a result, it is difficult to locate and trace logs. For this type of problem, Logback provides MDC (Mapped Diagnostic Context Mapping), which allows developers to place information in Diagnostic context. These messages internally use ThreadLocal to implement data isolation between threads and manage context information for each thread. During log output, you can use the identifier %X{key} to output the Settings in the MDC. Therefore, when a distributed application is tracking requests, the implementation idea is as follows:

In a Web application, add an interceptor that adds a unique ID as the request comes inrequest-idTo identify the request.
Add thisrequest-idIn the MDC
If you need to invoke other services, use thisrequest-idAs a header argument
Add this when logging outputrequest-idThe output of the
Clear this when the request is completerequest-id

5.1 Adding An Interceptor

5.1.1 Interceptor implementation

Through interceptors, request-IDS are added before requests and stored in MDC. The action of clearing after a request has been completed. Add the package Interceptor to store the interceptor class, which is defined as follows:

@Slf4j
@Component
public class RequestIdTraceInterceptor implements HandlerInterceptor {

    public static final String REQUEST_ID_KEY = "request-id";

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
        MDC.put(REQUEST_ID_KEY, getRequestId(request));
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) {
        // Add requestId to the response header for use by other applications
        response.addHeader(REQUEST_ID_KEY, MDC.get(REQUEST_ID_KEY));
        // Request complete, requestId removed from MDC
        MDC.remove(REQUEST_ID_KEY);
    }
    
    public static String getRequestId(HttpServletRequest request) {...}}
}
Copy the code

This interceptor primarily overrides the preHandle and afterCompletion methods, processing before and after the request, respectively. Mdc.put () and mdC.remove () are used to write and clear MDC nodes.

To get the request-id, use getRequestId() as follows:

public static String getRequestId(HttpServletRequest request) {
    String requestId;
    String parameterRequestId = request.getParameter(REQUEST_ID_KEY);
    String headerRequestId = request.getHeader(REQUEST_ID_KEY);
    // Check whether request-id exists according to request parameters or request headers. If yes, use request-id. If no, create request-id
    if (parameterRequestId == null && headerRequestId == null) {
        log.debug("no request-id in request parameter or header");
        requestId = IdUtil.simpleUUID();
    } else{ requestId = parameterRequestId ! =null ? parameterRequestId : headerRequestId;
    }

    return requestId;
}
Copy the code

Check whether request-id exists according to the request parameters or request header. If yes, the request-id is used; if no, the request-id is created. The request-id is simpleUUID, which serves as the unique identifier.

5.1.2 Registering an interceptor in the Web configuration

Add config package to store configuration files. AddInterceptors inherit WebMvcConfigurer to addInterceptors to the web configuration:

@Configuration
public class WebAppConfig implements WebMvcConfigurer {
    @Autowired
    RequestIdTraceInterceptor requestIdTraceInterceptor;

    /** * Add interceptor *@param registry
     */
    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        / / add requestIdregistry.addInterceptor(requestIdTraceInterceptor); }}Copy the code

5.2 Configuring MDC Log Output

The logback MDC output uses %X{key} as an identifier. Therefore, modify the logback-spring. XML file to add %X{request-id} to the output format as follows:

<property name="log.pattern"
              value="%d{YYYY-MM-DD HH: MM :ss.SSS} %5level [% 10Thread] [%X{request-id}] %40.40 Logger {40} [%10method,%line] : % MSG %n"/>
Copy the code

At this point, the MDC processed, start the application, visit one of these interfaces, the output shown in the following (among them 8 e955ff61fa7494788f52891a4fdbc6a can request – id) :

Note that the sample code does not show what happens when other services are called. When called, request-ID is obtained from MDC and passed as a header parameter. This allows tracing based on this ID when querying logs.

6. Summary

This article focuses on how to better use Logback to solve the problems related to log output in springboot application development, including loback status data output, using asynchronous log output performance problems, configuring log output in multiple environments and using MDC to solve distributed application tracing requests. I hope it’s helpful.

The sample code used in this article has been placed on my Github: https://github.com/mianshenglee/my-example/tree/master/springboot-logback-demo, interested students can pull code, combined with the example study together.

The resources

Logback website: http://logback.qos.ch
Logback Chinese manual: http://www.logback.cn/
Logback github:https://github.com/qos-ch/logback
Using requestId in a distributed system to track the request: https://juejin.cn/post/6844903641535479821

The articles

Springboot + Logback Log output
Springboot + Swagger Interface Documentation
Springboot + Swagger Interface Documentation
After consulting more than ten learning resources, I summarized this AI learning path
Java Application Monitoring (8)- Arthas Diagnostics tool
Java Application Monitoring (7)- Online dynamic diagnostic artifact BTrace

Follow my official account (search Mason technical records) for more technical records:

mo4tech.com (Moment For Technology) is a global community with thousands techies from across the global hang out!Passionate technologists, be it gadget freaks, tech enthusiasts, coders, technopreneurs, or CIOs, you would find them all here.

Springboot + Logback Log Output

1. The introduction

2. Output logBack status data

3. Logback Generates logs asynchronously

3.1 Asynchronous Output Configuration

3.2 Principle of Asynchronous Output

4. Configure Logback in a SpringBoot multi-environment

5. The MDC distributed application traces requests

5.1 Adding An Interceptor

5.1.1 Interceptor implementation

5.1.2 Registering an interceptor in the Web configuration

5.2 Configuring MDC Log Output

6. Summary

The resources

The articles

Springboot + Logback Log Output

1. The introduction

2. Output logBack status data

3. Logback Generates logs asynchronously

3.1 Asynchronous Output Configuration

3.2 Principle of Asynchronous Output

4. Configure Logback in a SpringBoot multi-environment

5. The MDC distributed application traces requests

5.1 Adding An Interceptor

5.1.1 Interceptor implementation

5.1.2 Registering an interceptor in the Web configuration

5.2 Configuring MDC Log Output

6. Summary

The resources

The articles

Related Posts

Architecture design: file service storage design

Algorithm – Determines whether the string is an IP address

2016, my summary of crawlers