The need for MDC

The logging framework

Logging frameworks are also more mature:

slf4j

log4j

logback

log4j2

There is no need to duplicate the wheel, it is generally recommended to integrate with SLF4J for later replacement with other frameworks.

Use of logs

Almost all applications require logging, but not every development does.

The main problems are as follows:

(1) Logs are too small, and problems cannot be located

(2) Too many logs, find the problem is very troublesome, the server disk is also a lot of pressure

(3) The log level is improperly controlled

(4) There is no unique identifier throughout the call link

Let’s focus on the fourth question.

Why do YOU need a unique identifier

For the most common Web applications, each request can be considered a new thread.

In the case of higher concurrency, our log will have an interlude. When we look at the log, we see logs that are not part of the current request, and it looks very tired. So you need a filter condition that connects the entire life cycle of a request, known as a traceId.

For example traceId=’202009021658001′, run the following command:

grep 202009021658001 app.log
Copy the code

You can filter out all logs corresponding to the link.

So how do you do that?

Implementation approach

(1) Generate a unique traceId

This one is relatively simple, such as UUID or something like that, just make sure it’s unique.

(2) This traceId is printed during log output

It is natural to have the following code:

logger.info("TraceId: {} Controller layer request parameters: {}", traceId, req);
Copy the code

defects

Many projects are implemented this way, and there are several problems with this approach:

(1) Parameter transfer is required

For example, from Controller = biz = service, because of a traceId, all of our methods need an extra parameter to accept this value.

Very inelegant

(2) traceId output is required

Remember to print this value every time, or not correlate.

If certain methods forget to output, it will be strange for us to look at the log based on traceId.

(3) Increased complexity

We need to block out this extra traceId for each log, and as a lazy person, we don’t want to block out this code.

So, is there a solution to this problem?

The SLF4J MDC exists to solve this problem.

MDC application scenarios

In the program, we sometimes need to trace the entire call link when the log is printed.

The most common approach is to pass an attribute, such as traceId, consistently down from the outermost layer.

This causes every method to have this extra parameter, just to print an identifier, which is not recommended.

MDC is used for this scenario.

A simple example

Common implementation version

Set manually before and after method calls.

This article presents aop in a more flexible and convenient way, with the same principle. The code is also more elegant.

Aop-based approach

Defining interceptors

import com.baomidou.mybatisplus.toolkit.IdWorker;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;

/** * log interceptor *@author binbin.hou
 * @date2018/12/7 * /
@Component
@Aspect
public class LogAspect {

    /** * Limit the number of trace times */
    private static final String TRACE_ID = "TRACE_ID";

    /** * block all public methods */ under the entry
    @Pointcut("execution(public * com.github.houbb.. * (..) )"
    public void pointCut(a) {}/** * Intercepting processing **@paramPoint Point information *@return result
     * @throws Throwable if any
     */
    @Around("pointCut()")
    public Object around(ProceedingJoinPoint point) throws Throwable {
        / / add the MDC
        MDC.put(TRACE_ID, IdWorker.getIdStr());
        Object result = point.proceed();
        / / remove the MDC
        MDC.remove(TRACE_ID);
        returnresult; }}Copy the code

Idworker.getidstr () is just used to generate a unique identifier, you can use UUID etc instead.

For more methods of generating unique identifiers, see:

A distributed ids

The AOP aspect is generally recommended to be placed at the entry of the call.

(1) Controller layer entrance

(2) MQ consumption entry

(3) External RPC request entry

Define logback. XML

With MDC defined, we can use it in the log configuration file.

<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
    <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%X{TRACE_ID}] [%thread] %logger{50} - %msg%n</pattern>
</encoder>
Copy the code

[%X{TRACE_ID}] is the unique identifier that we need to use in our system, which will be printed in the log after configuration.

If it does not exist, it is an empty string and it does not matter.

For existing systems

The phenomenon of

What would you do if you had an existing project, the original print log, that passed the order number all the way down from the top?

Same thing, pass an id from the very beginning all the way down to the very bottom?

Of course not.

You can do better than that.

The principle of

We know that MDC works by placing a property in the current thread that is unique and shared within the same thread.

So the different threads don’t interfere with each other.

So for older systems, we can take the simplest approach:

Provides a utility class that gets the order number of the current thread. Of course, you need to set this value to the current thread in one place, usually the method entry.

A better way

You can provide a log printing utility class that duplicates common log printing methods.

Hide log traceId information from development.

Implementation ThreadLocal

Without further ado, see ThreadLocal

Basic utility classes

import org.slf4j.MDC;

/** * log tools *@author binbin.hou
 */
public final class LogUtil {

    private LogUtil(a){}

    /** * trace id */
    private static final String TRACE_ID = "TRACE_ID";

    /** * Set traceId *@param traceId traceId
     */
    public static void setTraceId(final String traceId) {
        MDC.put(TRACE_ID, traceId);
    }

    /** * Remove traceId */
    public static void removeTraceId(a) {
        MDC.remove(TRACE_ID);
    }

    /** * Get batch number *@returnBatch number * /
    public static String getTraceId(a) {
        returnMDC.get(TRACE_ID); }}Copy the code

For asynchronous processing

Spring asynchronous

See async async

Asynchronous traceId processing

In asynchrony, another thread is created.

You are advised to pass the traceId of the parent thread as a parameter and set this parameter to the traceId of the child thread.

Do not rely on the MDC

The MDC restrictions

MDC, while easier to use, is a tool that SLF4J implements for us.

The idea is to store thread-isolated identials based on ThreadLocal.

With this in mind, we can actually implement an MDC-like feature for different application scenarios.

Implementation approach

(1) Generate a unique log identifier

(2) Store a unique thread identifier based on ThreadLocal

(3) Annotation based +AOP

@Around("@annotation(trace)")
public Object trace(ProceedingJoinPoint joinPoint, Trace trace) {

    / / generated id
    // Set the id to the current thread

    Object result = joinPoint.proceed();    
    / / remove the id
    return result;
}
Copy the code

(4) How to use ID

The simplest way to do this is to create a utility class called LogUtil.

Override the common method, and log output calls this method uniformly.

Disadvantages: The output class in the log will not be visible, of course, can be solved through the fetch method

Advantages: simple implementation, easy to expand and replace later.

Github.com/houbb/auto-…

Open source tools

Auto-log is an automatic log monitoring framework designed for Java.

Writing purpose

Tools are often written, sometimes adding logs manually is cumbersome, and introducing Spring is overkill.

So I hope to achieve a tool from simple to complex, easy to use at ordinary times.

features

Flexible configuration based on annotations + bytecode
Automatically ADAPTS to common logging frameworks
Support for programmatic calls
Annotated support for perfect spring integration
Support for spring-boot integration
Supports slow log threshold, time, input and output parameters, exception information and other common attributes
Supports the traceId feature

Change log

Quick start

Maven is introduced into

<dependency>
    <group>com.github.houbb</group>
    <artifact>auto-log-core</artifact>
    <version>0.0.8</version>
</dependency>
Copy the code

An introduction to case

UserService userService = AutoLogHelper.proxy(new UserServiceImpl());
userService.queryLog("1");
Copy the code

Log as follows

[the INFO] [the 2020-05-29 16:24:06. 227] [the main] [C.G.H.A.L.C.S.I.A utoLogMethodInterceptor. Invoke] - public Java. Lang. String com.github.houbb.auto.log.test.service.impl.UserServiceImpl.queryLog(java.lang.String) param is [1] [INFO] [2020-05-29 16:24:06. 228] [the main] [C.G.H.A.L.C.S.I.A utoLogMethodInterceptor. Invoke] - public Java. Lang. String com.github.houbb.auto.log.test.service.impl.UserServiceImpl.queryLog(java.lang.String) result is result-1Copy the code

code

The method is as follows:

UserService.java

public interface UserService {

    String queryLog(final String id);

}
Copy the code

UserServiceImpl.java

Use the @autolog annotation to specify which logging method is required.

public class UserServiceImpl implements UserService {

    @Override
    @AutoLog
    public String queryLog(String id) {
        return "result-"+id; }}Copy the code

An example of TraceId

code

UserService service =  AutoLogProxy.getProxy(new UserServiceImpl());
service.traceId("1");
Copy the code

The traceId methods are as follows:

@AutoLog
@TraceId
public String traceId(String id) {
    return id+"1";
}
Copy the code

The test results

Information: [ba7ddaded5a644e5a58fbd276b6657af] < traceId > into arguments: [1]. Information: [ba7ddaded5a644e5a58fbd276b6657af] < traceId > reference: 1-1.Copy the code

One of ba7ddaded5a644e5a58fbd276b6657af is corresponding traceId, throughout the thread cycle, can facilitate our log viewer.

Note that

@AutoLog

The attributes of the core annotation @Autolog are described as follows:

attribute	type	The default value	instructions
param	boolean	true	Whether to print input parameters
result	boolean	true	Whether to print the parameter
costTime	boolean	false	Print time
exception	boolean	true	Check whether printing is abnormal.
slowThresholdMills	long	– 1	If the value is greater than or equal to 0 and the time consumed exceeds the configured value, slow logs are generated
description	string	“”	Method description, method name is selected by default

@TraceId

@traceid is placed on methods that need to set TraceId, such as the Controller layer, the consumer of MQ, the recipient of RPC requests, etc.

attribute	type	The default value	instructions
id	Class	The default is uuid	Implementation policy of traceId
putIfAbsent	boolean	false	Whether to set a value when the current thread has no value

Spring integration

See SpringServiceTest for a complete example

Annotation statement

Use @enableautolog to enable automatic log output

@Configurable
@ComponentScan(basePackages = "com.github.houbb.auto.log.test.service")
@EnableAutoLog
public class SpringConfig {}Copy the code

The test code

@ContextConfiguration(classes = SpringConfig.class)
@RunWith(SpringJUnit4ClassRunner.class)
public class SpringServiceTest {

    @Autowired
    private UserService userService;

    @Test
    public void queryLogTest(a) {
        userService.queryLog("1"); }}Copy the code

The output

Information: public java.lang.String com.github.houbb.auto.log.test.service.impl.UserServiceImpl.queryLog(java.lang.String) param is [1] on May 30, 2020 com 12:17:51 afternoon. Making. Houbb. Auto. The core. Support. The interceptor. AutoLogMethodInterceptor info information: public java.lang.String com.github.houbb.auto.log.test.service.impl.UserServiceImpl.queryLog(java.lang.String) result is Result - 1 May 30, 2020 12:17:51 afternoon org. Springframework. Context. Support. GenericApplicationContext doCloseCopy the code

Integrated use of Springboot

Maven is introduced into

<dependency>
    <groupId>com.github.houbb</groupId>
    <artifactId>auto-log-springboot-starter</artifactId>
    <version>0.0.8</version>
</dependency>
Copy the code

Just import the JAR and configure nothing else.

Use the same way as Spring.

test

@Autowired
private UserService userService;

@Test
public void queryLogTest(a) {
    userService.query("spring-boot");
}
Copy the code

Open source address

Making: github.com/houbb/auto-…

Gitee: gitee.com/houbinbin/a…

Develop reading

Distributed ID generation

Automatic Log Output

The resources

SLF4j traceID

SLF4J MDC mechanism is used to realize log link tracing

Java annotations combined with Spring AOP implement log traceId unique identification

The need for MDC

The logging framework

Use of logs

Why do YOU need a unique identifier

Implementation approach

defects

MDC application scenarios

A simple example

Common implementation version

Aop-based approach

Defining interceptors

Define logback. XML

For existing systems

The phenomenon of

The principle of

A better way

Implementation ThreadLocal

Basic utility classes

For asynchronous processing

Spring asynchronous

Asynchronous traceId processing

Do not rely on the MDC

The MDC restrictions

Implementation approach

Open source tools

Writing purpose

features

Quick start

Maven is introduced into

An introduction to case

code

An example of TraceId

code

The test results

Note that

@AutoLog

@TraceId

Spring integration

Annotation statement

The test code

Integrated use of Springboot

Maven is introduced into

test

Open source address

Develop reading

The resources

Related Posts

Flink series 1.10 data stream programming model

Look for the maximum value in each tree line

Spring Boot integration Netty (including source code) will not send blade to me after reading