Through MDC, you can easily track your scheduled task log

When our program appears debug When , Our general solution is to check the log . It's OK in the development environment , Our local startup service usually has only one request , View logs or local debug It's very convenient . But if we have problems online , At this time, there are more requests . If our call chain is long , It is not convenient to associate the whole log . At this time, we need to use the log MDC 了 .

The following is the log framework logback Of MDC , Of course, mainstream logging frameworks basically support this feature . Simply speaking ：MDC In fact, a lighter technique is to uniquely mark each log request serving a given client . The general implementation is as follows ：

• Call... In the program entry MDC.put( Tracking number , The only mark ) , Put the trace number in the context of the log framework
• Then in the log template, you can [%X{ Tracking number }], When the log is printed, each call will carry the tracking number of this unique mark ( Cannot cross thread )

It's going on RPC When called , We can connect the whole calling chain in a microservice completely according to the trace number passed upstream . But if we have problems with our scheduled tasks , How can we view the whole call chain through logs ？

In fact, when we call a task , Manually add a tracking number before the task is executed , After the task call is completed, you can clear the trace number . But this requires the same operation to be performed on each task . Then the blogger wants to use the template to call . Here is a reference Spring Template processing logic .

First, define an interface to handle the real task logic ( It can be understood as Spring Transaction processing TransactionCallback)

Business processing interface definitions

@FunctionalInterface
public interface LoggerCallback<T> {
    

    /** *  Task operation  * @return */
    T doInExecute();

}

Then we define a log template .

Log template

public class LoggerTemplate {
    

    public <T> T execute(String mdcKey, JobLoggerCallback<T> action){
    
        String uuid = UUID.randomUUID().toString().replaceAll("-", "");
        MDC.put(mdcKey, uuid);
        try {
    
            return action.doInExecute();
        } finally {
    
            MDC.clear();
        }
    }

}

Through this log template, we add it before the business call starts MDC Tracking number , Then call clear... After the call is complete MDC Tracking number .

Now I will xxl-job Examples of task operations .

@Slf4j
@Component
public class DemoJob {
    

    @Resource(name = "loggerTemplate")
    protected LoggerTemplate loggerTemplate;

    @XxlJob(value = "demoJob")
    public ReturnT<String> execute(String param) {
    
        return loggerTemplate.execute("ctxLogId", () -> {
    
            log.info("DemoJob.execute task Start ......");
            try {
    
                // TODO  Perform business operations 
            } catch (Exception e) {
    
                LogUtil.error("DemoJob.execute is error", e);
                return ReturnT.FAIL;
            }
            log.info("DemoJob.execute task End ......");
            return ReturnT.SUCCESS;
        });
    }

}

Let's think about , When performing defined tasks , We are all batch operation data . If the batch of our operation is large , But there is only one piece of data for our execution exception . At this time, we can query a large amount through the above tracking number . Then we can associate all the tasks on the through the above tracking number , Then we add our unique business number to the previous tracking number when we perform a single data operation . In this way, we can give consideration to both .

Let's just add a method to the log template , The added log template code is as follows ：

public class LoggerTemplate {
    

    public <T> T execute(String mdcKey, JobLoggerCallback<T> action){
    
        String uuid = UUID.randomUUID().toString().replaceAll("-", "");
        MDC.put(mdcKey, uuid);
        try {
    
            return action.doInExecute();
        } finally {
    
            MDC.clear();
        }
    }

    public <T> T render(String mdcKey, String appendValue, JobLoggerCallback<T> action){
    
        String mdc = MDC.get(mdcKey);
        String newMdc = StringUtils.join(mdc, ":", appendValue);
        MDC.put(mdcKey, newMdc);
        try {
    
            return action.doInExecute();
        } finally {
    
            MDC.put(mdcKey, mdc);
        }
    }

}

Here we need to pay attention to , After the completion logic is executed , Need to put the original MDC Trace number added back to MDC Inside , Because subsequent tasks still need to use .

The logic for us to deal with timed tasks is as follows ：

@Slf4j
@Component
public class DemoJob {
    

    @Resource(name = "loggerTemplate")
    protected LoggerTemplate loggerTemplate;

    @XxlJob(value = "demoJob")
    public ReturnT<String> execute(String param) {
    
        return loggerTemplate.execute("ctxLogId", () -> {
    
            log.info("DemoJob.execute task Start ......");
            try {
    
                // TODO  Query the data that the database needs to process 
                List list =  getDataForDB();
                
                if(CollectionUtils.isEmpty(list)) {
    
                    return;
                }
                
                list.stream().forEach(v -> {
    
                    loggerTemplate.render("ctxLogId", v.getId(), 
                    new LoggerCallbackWithoutResult() {
    
	                @Override
	                protected void doInExecuteWithoutResult() {
    
	                    processOne(v);
	                }
                });
            } catch (Exception e) {
    
                LogUtil.error("DemoJob.execute is error", e);
                return ReturnT.FAIL;
            }
            log.info("DemoJob.execute task End ......");
            return ReturnT.SUCCESS;
        });
    }

    /** *  Process a single business logic  * @param v */
    private void processOne(Object v) {
    
        // TODO  Process business logic 
    }

}