技术分享-日志链路追踪

发布时间:2026/5/20 0:39:19

技术分享-日志链路追踪 1.背景简述在技术运维过程中很难从某服务庞杂的日志中单独找寻出某次API调用的全部日志。为提高排查问题的效率在多个系统及应用内根据 统一的TraceId 查找同一次请求链路上的日志根据日志快速定位问题同时需对业务代码无侵入特别是在高频请求下也可以方便的搜索此次请求的日志内容。本此分享一个使用MDC实现日志链路跟踪在微服务环境中我们经常使用Skywalking、Spring Cloud Sleut等去实现整体请求链路的追踪但是这个整体运维成本高架构复杂本次我们来使用MDC通过Log来实现一个轻量级的会话事务跟踪功能,需要的朋友可以参考一下。应用效果图我们知道了MDC的好处后其实在用户从第一时间调用请求时候我们其实可以将请求增加tarceid一并返回这样用户反馈时候我们直接用traceid就可以全链路追踪到所有请求的情况了做到信息的闭环。请求效果图LOGBOOK效果图2.关键思路2.1.MDC日志追踪目标是每次请求级别的也就是说同一个接口的每次请求都应该有不同的traceId。 每次接口请求都是一个单独的线程所以自然我们很容易考虑到通过ThreadLocal实现上述需求。 考虑到log4j本身已经提供了类似的功能MDC所以直接使用MDC进行实现。关于MDC的简述MDCMapped Diagnostic Context是一个映射用于存储运行上下文的特定线程的上下文数据。因此如果使用log4j进行日志记录则每个线程都可以拥有自己的MDC该MDC对整个线程是全局的。属于该线程的任何代码都可以轻松访问线程的MDC中存在的值。API说明•clear() 移除所有MDC•get (String key) 获取当前线程MDC中指定key的值•getContext() 获取当前线程MDC的MDC•put(String key, Object o) 往当前线程的MDC中存入指定的键值对•remove(String key) 删除当前线程MDC中指定的键值对 。3.目标1.需要一个全服务唯一的id即traceId如何保证2.traceId如何在服务内部传递3.traceId如何在服务间传递4.traceId如何在多线程中传递4、实现方式4.1 需要一个全服务唯一的id即traceId如何保证使用最简单的uuid即可。复杂的话可以配置redis雪花算法等方式。本次分享选最简单uuid生成traceId的方式。4.2 traceId如何在服务间传递1在xml的日志格式中添加 %X{traceId} 配置。appender nameCONSOLE classorg.apache.log4j.ConsoleAppenderlayout classorg.apache.log4j.PatternLayoutparam nameConversionPattern value%d{yyyy-MM-dd HH:mm:ss} [%X{traceId}] [%p] %l[%t]%n%m%n//layout/appender2新增拦截器拦截所有请求从 header 中获取 traceId 然后放到 MDC 中如果没有获取到则直接用 UUID 生成一个。Slf4jComponentpublic class LogInterceptor implements HandlerInterceptor {private static final String TRACE_ID traceId;Overridepublic void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception arg3) throws Exception {}Overridepublic void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView arg3) throws Exception {}Overridepublic boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {String traceId request.getHeader(TRACE_ID);if (StringUtils.isEmpty(traceId)) {MDC.put(TRACE_ID, UUID.randomUUID().toString());} else {MDC.put(TRACE_ID, traceId);}return true;}}3配置拦截器Configurationpublic class WebConfig implements WebMvcConfigurer {Resourceprivate LogInterceptor logInterceptor;Overridepublic void addInterceptors(InterceptorRegistry registry) {registry.addInterceptor(logInterceptor).addPathPatterns(/**);}}4.3 traceId如何在服务间传递封装Http工具类把traceId加入头中带到下一个服务。Slf4jpublic class HttpUtils {public static String get(String url) throws URISyntaxException {RestTemplate restTemplate new RestTemplate();MultiValueMapString, String headers new HttpHeaders();headers.add(traceId, MDC.get(traceId));URI uri new URI(url);RequestEntity? requestEntity new RequestEntity(headers, HttpMethod.GET, uri);ResponseEntityString exchange restTemplate.exchange(requestEntity, String.class);if (exchange.getStatusCode().equals(HttpStatus.OK)) {http://log.info(send http request success);}return exchange.getBody();}}4.4 traceId如何在多线程中传递spring项目也使用到了很多线程池比如Async异步调用zookeeper线程池、kafka线程池等。不管是哪种线程池都大都支持传入指定的线程池实现拿Async举例原理为MDC底层使用TreadLocal来实现那根据TreadLocal的特点它是可以让我们在同一个线程中共享数据的但是往往我们在业务方法中会开启多线程来执行程序这样的话MDC就无法传递到其他子线程了。这时我们需要使用额外的方法来传递存在TreadLocal里的值。MDC提供了一个叫getCopyOfContextMap的方法很显然该方法就是把当前线程TreadLocal绑定的Map获取出来之后就是把该Map绑定到子线程中的ThreadLocal中了改造Spring的异步线程池包装提交的任务。Slf4jComponentpublic class TraceAsyncConfigurer implements AsyncConfigurer {Overridepublic Executor getAsyncExecutor() {ThreadPoolTaskExecutor executor new ThreadPoolTaskExecutor();executor.setCorePoolSize(8);executor.setMaxPoolSize(16);executor.setQueueCapacity(100);executor.setThreadNamePrefix(async-pool-);executor.setTaskDecorator(new MdcTaskDecorator());executor.setWaitForTasksToCompleteOnShutdown(true);executor.initialize();return executor;}Overridepublic AsyncUncaughtExceptionHandler getAsyncUncaughtExceptionHandler() {return (throwable, method, params) - log.error(asyc execute error, method{}, params{}, method.getName(), Arrays.toString(params));}public static class MdcTaskDecorator implements TaskDecorator {Overridepublic Runnable decorate(Runnable runnable) {MapString, String contextMap MDC.getCopyOfContextMap();return () - {if (contextMap ! null) {MDC.setContextMap(contextMap);}try {runnable.run();} finally {MDC.clear();}};}}}public class MDCLogThreadPoolExecutor extends ThreadPoolExecutor {public MDCLogThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueueRunnable workQueue) {super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);}Overridepublic void execute(Runnable command) {super.execute(MDCLogThreadPoolExecutor.executeRunable(command, MDC.getCopyOfContextMap()));}Overridepublic Future? submit(Runnable task) {return super.submit(MDCLogThreadPoolExecutor.executeRunable(task, MDC.getCopyOfContextMap()));}Overridepublic T FutureT submit(CallableT callable) {return super.submit(MDCLogThreadPoolExecutor.submitCallable(callable,MDC.getCopyOfContextMap()));}public static Runnable executeRunable(Runnable runnable ,MapString,String mdcContext){return new Runnable() {Overridepublic void run() {if (mdcContext null) {MDC.clear();} else {MDC.setContextMap(mdcContext);}try {runnable.run();} finally {MDC.clear();}}};}private static T CallableT submitCallable( CallableT callable, MapString, String context) {return () - {if (context null) {MDC.clear();} else {MDC.setContextMap(context);}try {return callable.call();} finally {MDC.clear();}};}}接下来需要对ThreadPoolTaskExecutor的方法进行重写package com.example.demo.common.threadpool;import com.example.demo.common.constant.Constants;import lombok.extern.slf4j.Slf4j;import org.slf4j.MDC;import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;import java.util.Map;import java.util.UUID;import java.util.concurrent.Callable;import java.util.concurrent.Future;/*** MDC线程池* 实现内容传递** author wangbo* date 2021/5/13*/Slf4jpublic class MdcTaskExecutor extends ThreadPoolTaskExecutor {Overridepublic T FutureT submit(CallableT task) {http://log.info(mdc thread pool task executor submit);MapString, String context MDC.getCopyOfContextMap();return super.submit(() - {T result;if (context ! null) {//将父线程的MDC内容传给子线程MDC.setContextMap(context);} else {//直接给子线程设置MDCMDC.put(Constants.LOG_MDC_ID, UUID.randomUUID().toString().replace(-, ));}try {//执行任务result task.call();} finally {try {MDC.clear();} catch (Exception e) {log.warn(MDC clear exception, e);}}return result;});}Overridepublic void execute(Runnable task) {http://log.info(mdc thread pool task executor execute);MapString, String context MDC.getCopyOfContextMap();super.execute(() - {if (context ! null) {//将父线程的MDC内容传给子线程MDC.setContextMap(context);} else {//直接给子线程设置MDCMDC.put(Constants.LOG_MDC_ID, UUID.randomUUID().toString().replace(-, ));}try {//执行任务task.run();} finally {try {MDC.clear();} catch (Exception e) {log.warn(MDC clear exception, e);}}});}}然后使用自定义的重写子类MdcTaskExecutor来实现线程池配置/*** 线程池配置** author wangbo* date 2021/5/13*/Slf4jConfigurationpublic class ThreadPoolConfig {/*** 异步任务线程池* 用于执行普通的异步请求带有请求链路的MDC标志*/Beanpublic Executor commonThreadPool() {http://log.info(start init common thread pool);//ThreadPoolTaskExecutor executor new ThreadPoolTaskExecutor();MdcTaskExecutor executor new MdcTaskExecutor();//配置核心线程数executor.setCorePoolSize(10);//配置最大线程数executor.setMaxPoolSize(20);//配置队列大小executor.setQueueCapacity(3000);//配置空闲线程存活时间executor.setKeepAliveSeconds(120);//配置线程池中的线程的名称前缀executor.setThreadNamePrefix(common-thread-pool-);//当达到最大线程池的时候丢弃最老的任务executor.setRejectedExecutionHandler(new ThreadPoolExecutor.DiscardOldestPolicy());//执行初始化executor.initialize();return executor;}/*** 定时任务线程池* 用于执行自启动的任务执行父线程不带有MDC标志不需要传递直接设置新的MDC* 和上面的线程池没啥区别只是名字不同*/Beanpublic Executor scheduleThreadPool() {http://log.info(start init schedule thread pool);MdcTaskExecutor executor new MdcTaskExecutor();executor.setCorePoolSize(10);executor.setMaxPoolSize(20);executor.setQueueCapacity(3000);executor.setKeepAliveSeconds(120);executor.setThreadNamePrefix(schedule-thread-pool-);executor.setRejectedExecutionHandler(new ThreadPoolExecutor.DiscardOldestPolicy());executor.initialize();return executor;}}5、扩展点5.1 JSF接口日志追踪的应用项目中也运用到了大量的jsf接口我们其实可以按照上述的思路进行服务间的传递。调用端// todo 不能在filter里面这么用RpcContext.getContext().setAttachment(user, zhanggeng);RpcContext.getContext().setAttachment(.passwd, 11112222); // .开头的对应上面的hidetruexxxService.yyy();// 再开始调用远程方法// 重要:下一次调用要重新设置之前的属性会被删除RpcContext.getContext().setAttachment(user, zhanggeng);RpcContext.getContext().setAttachment(.passwd, 11112222); // .开头的对应上面的hidetruexxxService.zzz();// 再开始调用远程方法Provider端1.filter中直接获取包括标记为hiden的参数。通过Rpccontext无法获取。2.String consumerToken (String) invocation.getAttachment(.passwd);1.服务端业务代码中直接获取2.String user RpcContext.getContext().getAttachment(user);tips调用链中的隐式传参注意在调用链例如A–B–CA和B都要隐私传参的时候由于是同一个线程会出现数据污染。例如A发参数P1给BB收到请求拿到P1同时要发参数P2给C那么C会直接拿到P1,P2。 这种情况就要求B收到P1然后设置P2调用C之前要求自己清空上下文数据RpcContext.getContext().clearAttachments();5.2 接口返回值应用我们知道了MDC的好处后其实在用户从第一时间调用请求时候我们其实可以将有误的请求增加tarceid一并返回这样用户反馈时候我们直接用traceid就可以全链路追踪到所有请求的情况了做到信息的闭环。效果图6、备注各位知道了日志追踪的原理其实很多应用场景可以继续补充例如MQJD的其他中间件也可以应用相同原理进行追踪。其实当了解了底层的原理后我们其实就可以了解到JD监控中间件PFinder监控等中间件是如何做的了本次由于时间情况就不进行扩展了各位可以线下去了解Skywalking 分布式链路追踪系统就可以知道万变不离其宗。

相关新闻