Background

The most commonly used method to develop and sort out system problems is to view system logs. In distributed environment, ELK is generally used to collect logs in a unified way. However, it is more troublesome to use log location in concurrent large time. Because a large number of logs of other users/threads are output and run together, it is difficult to filter out the finger. All relevant logs for fixed requests and logs for downstream threads/services.

II. Solutions

• Each request uses a unique identifier to track all links displayed in the log, and does not modify the original printing method (no code intrusion)
• TraceId identifier is added to the log template of MDC mechanism using Logback, and the value is% X{traceId}.

MDC (Mapped Diagnostic Context, Mapped Debugging Context) is a convenient logging function provided by log4j and logback under multi-threaded conditions. MDC can be seen as a Map bound to the current thread to which key-value pairs can be added. The content contained in MDC can be accessed by code executed in the same thread. Subthreads of current threads inherit the contents of MDC in their parent threads. When you need to log, you just need to get the information you need from the MDC. MDC content is saved by the program at the appropriate time. For a Web application, this data is usually saved at the very beginning of the request being processed.

III. Program Realization

Because the ThreadLocal is used in MDC, only this thread is valid, and the values in sub-threads and downstream service MDC will be lost; therefore, the main difficulty of the solution is to solve the problem of value transfer.

3.1. Modify the log template

logback Profile Template Format Adds Identification%X{traceId}

3.2. Gateway Add Filter

Generate traceId and pass it to downstream services through header

@Component
public class TraceFilter extends ZuulFilter {
    @Autowired
    private TraceProperties traceProperties;

    @Override
    public String filterType() {
        return FilterConstants.PRE_TYPE;
    }

    @Override
    public int filterOrder() {
        return FORM_BODY_WRAPPER_FILTER_ORDER - 1;
    }

    @Override
    public boolean shouldFilter() {
        //Control whether to turn on the filter according to configuration
        return traceProperties.getEnable();
    }

    @Override
    public Object run() {
        //Link tracking id
        String traceId = IdUtil.fastSimpleUUID();
        MDC.put(CommonConstant.LOG_TRACE_ID, traceId);
        RequestContext ctx = RequestContext.getCurrentContext();
        ctx.addZuulRequestHeader(CommonConstant.TRACE_ID_HEADER, traceId);
        return null;
    }
}

3.3. Adding spring interceptors to downstream services

Receive and save the value of traceId
Interceptor

public class TraceInterceptor implements HandlerInterceptor {
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
        String traceId = request.getHeader(CommonConstant.TRACE_ID_HEADER);
        if (StrUtil.isNotEmpty(traceId)) {
            MDC.put(CommonConstant.LOG_TRACE_ID, traceId);
        }
        return true;
    }
}

Registered Interceptor

public class DefaultWebMvcConfig extends WebMvcConfigurationSupport {
  @Override
  protected void addInterceptors(InterceptorRegistry registry) {
    //Log Link Tracking Interceptor
    registry.addInterceptor(new TraceInterceptor()).addPathPatterns("/**");

    super.addInterceptors(registry);
  }
}

3.4. Adding feign interceptors to downstream services

Continue to pass the traceId value of the current service to the downstream service

public class FeignInterceptorConfig {
    @Bean
    public RequestInterceptor requestInterceptor() {
        RequestInterceptor requestInterceptor = template -> {
            //Transfer log traceId
            String traceId = MDC.get(CommonConstant.LOG_TRACE_ID);
            if (StrUtil.isNotEmpty(traceId)) {
                template.header(CommonConstant.TRACE_ID_HEADER, traceId);
            }
        };
        return requestInterceptor;
    }
}

3.5. Extended thread pool

Mainly for business use thread pool (asynchronous, parallel processing), and spring itself has @Async annotation to use thread pool, so we need to expand ThreadPoolTaskExecutor thread pool to copy the MDC content of the parent thread to the child thread.

public class CustomThreadPoolTaskExecutor extends ThreadPoolTaskExecutor {
    /**
     * Assign the MDC content of the parent thread to the child thread
     * @param runnable
     */
    @Override
    public void execute(Runnable runnable) {
        Map<String, String> mdcContext = MDC.getCopyOfContextMap();
        super.execute(() -> run(runnable, mdcContext));
    }

    @Override
    public <T> Future<T> submit(Callable<T> task) {
        Map<String, String> mdcContext = MDC.getCopyOfContextMap();
        return super.submit(() -> call(task, mdcContext));
    }

    /**
     * Execution Method of Subthread Delegation
     * @param runnable {@link Runnable}
     * @param mdcContext Parent thread MDC content
     */
    private void run(Runnable runnable, String tenantId, Map<String, String> mdcContext) {
        // Pass the MDC content of the parent thread to the child thread
        if (mdcContext != null) {
            MDC.setContextMap(mdcContext);
        }
        try {
            // Perform asynchronous operations
            runnable.run();
        } finally {
            // Clean up MDC content
            MDC.clear();
        }
    }

    /**
     * Execution Method of Subthread Delegation
     * @param task {@link Callable}
     * @param mdcContext Parent thread MDC content
     */
    private <T> T call(Callable<T> task, Map<String, String> mdcContext) throws Exception {
        // Pass the MDC content of the parent thread to the child thread
        if (mdcContext != null) {
            MDC.setContextMap(mdcContext);
        }
        try {
            // Perform asynchronous operations
            return task.call();
        } finally {
            // Clean up MDC content
            MDC.clear();
        }
    }
}

Scenario Testing

4.1. The test code is as follows

4.2. api Gateway Printed Logs

Gateway generation traceId value is 13d9800c8c7944c78a06ce28c36de670

 

4.3. Printed logs when requesting to jump to file services

The traceId shown is the same as the gateway, where exceptional scenarios are deliberately simulated

 

4.4. ELK aggregated log queries the entire link log through traceId

When an exception occurs to the system, all log information for the request can be queried in the log center directly through the value of traceId of the exception log.

V. Source Download

Attached is my open source microservice framework (including the code in this article), welcome to star's attention

https://gitee.com/zlt2000/mic...