MDC is introduced
MDC(Mapped Diagnostic Context) is a feature provided by LOG4J, LogBack, and Log4j2 to facilitate logging in multi-threaded conditions. MDC can be thought of as a hash table bound to the current thread to which you can add key-value pairs. The content contained in MDC can be accessed by code executing in the same thread. Children of the current thread inherit MDC content from their parent thread. To record logs, you only need to obtain the required information from the MDC.
API specification:
- Clear () => Remove all MDC nodes
- Get (String key) => Obtains the value of the specified key in the current MDC thread
- GetContext () => Get the MDC of the current thread MDC
- Put (String key, Object O) => Stores the specified key-value pair to the MDC of the current thread
- Remove (String key) => Delete the key/value pairs specified in the current MDC thread.
The MDC use
- The interceptor
@Component public class LogInterceptor implements HandlerInterceptor { @Override public boolean preHandle(HttpServletRequest request, HttpServletResponse response, String traceId = request.getheader (traceidUtil.trace_id); String traceId = request.getheader (traceidUtil.trace_id); if (StringUtil.isEmpty(traceId)) { TraceIdUtil.setTraceId(TraceIdUtil.generateTraceId()); } else { TraceIdUtil.setTraceId(traceId); } return true; } @Override public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception { } @Override public void afterCompletion(HttpServletRequest request, HttpServletResponse Response, Object Handler, Exception ex) throws Exception {// Remove traceidUtil.remove (); }}Copy the code- Utility class
public class TraceIdUtil
{
public static final String TRACE_ID = "requestId";
public static String getTraceId()
{
String traceId =(String) MDC.get(TRACE_ID);
return traceId == null ? "" : traceId;
}
public static void setTraceId(String traceId)
{
MDC.put(TRACE_ID,traceId);
}
public static void remove()
{
MDC.remove(TRACE_ID);
}
public static void clear()
{
MDC.clear();
}
public static String generateTraceId() {
return UUID.randomUUID().toString().replace("-", "");
}
Copy the code- Log File Configuration
<property name="LOG_PATTERN" value="%date{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level [%X{requestId}] %logger{36} - %msg%n" />
Copy the codeThe important point is that %X{requestId},requestId and MDC key names are the same.
Problems with the MDC
So far the basic function has been realized, but there are several problems
- In multi-threaded cases, the traceId is lost when logs are printed on sub-threads.
- The INVOCATION between HTTP services lost traceId. Procedure
Description The traceId of child thread logs is lost
Problem reproduction
@logAnnotation (model=" user management ",func=" query user information ",desc=" By user name ") @getMapping ("getUserByName") public Result GetUserByName (@requestParam String name) {// Mainline log logger.info("getUserByName paramter Name :"+name); for(int i=0; i<5; I++) {/ / the child thread log threadPoolTaskExecutor. Execute (() - > {logger. The info (" child thread: {} ", name); userService.getUserByName(name); }); } return Result.success(); }Copy the codeThe results
2022-03-13 12:45:44. 156 [HTTP - nio - 8089 - exec - 1] INFO/ec05a600ed1a4556934a3afa4883766a C.S.F w.c ontroller. UserController 173 - getUserByName paramter name: 1 2022-03-13 12:45:44. [the Pool - A1] INFO [] C.S.F w.c ontroller. UserController - child thread:1Copy the codeThe sub-thread generates logs, and traceId information in the logs is lost.
The solution
TraceId will be lost in the process of printing logs for child threads. The solution is to override the Thread pool (not mentioned in the case of threads created by direct new threads), which is also prohibited in practical development.
public class ThreadPoolExecutorMdcWrapper extends ThreadPoolTaskExecutor
{
private static final long serialVersionUID = 3940722618853093830L;
@Override
public void execute(Runnable task)
{
super.execute(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
}
@Override
public <T> Future<T> submit(Callable<T> task)
{
return super
.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
}
@Override
public Future<?> submit(Runnable task)
{
return super
.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
}
}
Copy the codeSince Spring Boot ThreadPoolTaskExecutor already encapsulates ThreadPoolExecutor, you only need to inherit the related execution methods of ThreadPoolTaskExecutor.
public class ThreadMdcUtil
{
public static void setTraceIdIfAbsent() {
if (MDC.get(TraceIdUtil.TRACE_ID) == null)
{
MDC.put(TraceIdUtil.TRACE_ID, TraceIdUtil.generateTraceId());
}
}
public static <T> Callable<T> wrap(final Callable<T> callable, final Map<String, String> context) {
return () -> {
if (context == null) {
MDC.clear();
} else {
MDC.setContextMap(context);
}
setTraceIdIfAbsent();
try {
return callable.call();
} finally {
MDC.clear();
}
};
}
public static Runnable wrap(final Runnable runnable, final Map<String, String> context) {
return () -> {
if (context == null) {
MDC.clear();
} else {
MDC.setContextMap(context);
}
//设置traceId
setTraceIdIfAbsent();
try {
runnable.run();
} finally {
MDC.clear();
}
};
}
}
Copy the codeCode description:
- Check whether the Map of the MDC for the current thread exists. If yes, set this parameter
- If the traceId value does not exist, a new traceId value is generated. If the value is a child thread, the traceId value is not null
- Execute the run method
Thread pool configuration
@ Configuration public class ThreadPoolTaskExecutorConfig {/ / maximum number of CPU cores available public static final ints PROCESSORS = Runtime.getRuntime().availableProcessors(); @Bean public ThreadPoolExecutorMdcWrapper getExecutor() { ThreadPoolExecutorMdcWrapper executor =new ThreadPoolExecutorMdcWrapper(); executor.setCorePoolSize(PROCESSORS *2); executor.setMaxPoolSize(PROCESSORS * 4); executor.setQueueCapacity(50); executor.setKeepAliveSeconds(60); executor.setThreadNamePrefix("Task-A"); executor.setRejectedExecutionHandler(new ThreadPoolExecutor.AbortPolicy()); executor.initialize(); return executor; }}Copy the codeThe child thread can obtain traceid information for tracing.
The 2022-03-13 13:19:30. 688 / Task - A1 INFO cbc4476a4e7168615af7890 [482929425] C.S.F w.c ontroller. UserController - child Thread: 1 2022-03-13 13:19:31. [Task - 003 A1] INFO cbc4476a4e7168615af7890 [482929425] C.S.F baron ervice. Impl. UserServiceImpl - name:1Copy the codeDescription HTTP invocation traceId is lost
The traceId is lost when the HTTP invokes the third-party service interface. You need to add the traceId to the Request Header when sending a Request, and add the interceptor to the invoked party to obtain the traceId in the Header and add the traceId to the MDC.
HTTP calls can be made in various ways, including HttpClient, OKHttp, and RestTemplate. The RestTemplate call is used as an example.
- Interface caller
public class RestTemplateTraceIdInterceptor implements
ClientHttpRequestInterceptor
{
@Override
public ClientHttpResponse intercept(HttpRequest request, byte[] body,
ClientHttpRequestExecution clientHttpRequestExecution) throws IOException
{
String traceId=MDC.get("requestId");
if(traceId!=null)
{
request.getHeaders().set("requestId", traceId);
}
else
{
request.getHeaders().set("requestId", UUID.randomUUID().toString().replace("-", ""));
}
return clientHttpRequestExecution.execute(request, body);
}
}
Copy the codeRestTemplate adds an interceptor.
restTemplate.setInterceptors(Arrays.asList(new RestTemplateTraceIdInterceptor()));
Copy the code2. Third-party services need to add interceptors.
@Component public class LogInterceptor implements HandlerInterceptor { @Override public boolean preHandle(HttpServletRequest request, HttpServletResponse response, String traceId = request.getheader (traceidUtil.trace_id); String traceId = request.getheader (traceidUtil.trace_id); if (StringUtil.isEmpty(traceId)) { TraceIdUtil.setTraceId(TraceIdUtil.generateTraceId()); } else { TraceIdUtil.setTraceId(traceId); } return true; } @Override public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception { } @Override public void afterCompletion(HttpServletRequest request, HttpServletResponse Response, Object Handler, Exception ex) throws Exception {// Remove traceidUtil.remove (); }}Copy the codeThe other HttpClient and OKHttp implementations are basically the same as RestTemplate. Spring Boot + Logback +MDC to achieve full link tracing content is covered. In practice, I have also found some problems with the use of logs. The next chapter will explain the usage of logs in development.