分布式系统中如何优雅地追踪日志（原理篇） (2)

改造Spring的异步线程池，包装提交的任务。

@Slf4j @Component public class TraceAsyncConfigurer implements AsyncConfigurer { @Override public 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; } @Override public AsyncUncaughtExceptionHandler getAsyncUncaughtExceptionHandler() { return (throwable, method, params) -> log.error("asyc execute error, method={}, params={}", method.getName(), Arrays.toString(params)); } public static class MdcTaskDecorator implements TaskDecorator { @Override public Runnable decorate(Runnable runnable) { Map<String, String> contextMap = MDC.getCopyOfContextMap(); return () -> { if (contextMap != null) { MDC.setContextMap(contextMap); } try { runnable.run(); } finally { MDC.clear(); } }; } } }

HttpUtils.java

封装Http工具类，把traceId加入头中，带到下一个服务。

@Slf4j public class HttpUtils { public static String get(String url) throws URISyntaxException { RestTemplate restTemplate = new RestTemplate(); MultiValueMap<String, String> headers = new HttpHeaders(); headers.add("traceId", MDC.get("traceId")); URI uri = new URI(url); RequestEntity<?> requestEntity = new RequestEntity<>(headers, HttpMethod.GET, uri); ResponseEntity<String> exchange = restTemplate.exchange(requestEntity, String.class); if (exchange.getStatusCode().equals(HttpStatus.OK)) { log.info("send http request success"); } return exchange.getBody(); } } A服务

A服务通过Http调用B服务。

@Slf4j @RestController public class AController { @RequestMapping("a") public String a(String name) { log.info("Hello, " + name); try { // A中调用B return HttpUtils.get("http://localhost:8002/b"); } catch (Exception e) { log.error("call b error", e); } return "fail"; } }

A服务的日志输出格式：

中间加了[%X{traceId}]一串表示输出traceId。

# 本文来源于工从号彤哥读源码 logging: pattern: console: '%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(%5p) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr([%X{traceId}]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n%wEx' B服务

B服务内部有两种跨线程调用：

利用Spring的异步线程池

使用自己的线程池

BController.java

@Slf4j @RestController public class BController { @Autowired private BService bService; @RequestMapping("b") public String b() { log.info("Hello, b receive request from a"); bService.sendMsgBySpring(); bService.sendMsgByThreadPool(); return "ok"; } }

BService.java

@Slf4j @Service public class BService { public static final TraceThreadPoolExecutor threadPool = new TraceThreadPoolExecutor(5, 5, 60, TimeUnit.SECONDS, new LinkedBlockingQueue<>(100)); @Async public void sendMsgBySpring() { log.info("send msg by spring success"); } public void sendMsgByThreadPool() { threadPool.execute(()->log.info("send msg by thread pool success")); } }

B服务的日志输出格式：

中间加了[%X{traceId}]一串表示输出traceId。

logging: pattern: console: '%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(%5p) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr([%X{traceId}]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n%wEx' 测试

打开浏览器，输入:8001/a?name=andy。

A服务输出日志：

2019-12-26 21:36:29.132 INFO 5132 --- [nio-8001-exec-2] [8a59cb96-bbc8-42a9-aa62-df7a52875447] com.alan.trace.a.AController : Hello, andy 2019-12-26 21:36:35.380 INFO 5132 --- [nio-8001-exec-2] [8a59cb96-bbc8-42a9-aa62-df7a52875447] com.alan.trace.common.HttpUtils : send http request success

B服务输出日志：

2019-12-26 21:36:29.244 INFO 2368 --- [nio-8002-exec-1] [8a59cb96-bbc8-42a9-aa62-df7a52875447] com.alan.trace.b.BController : Hello, b receive request from a 2019-12-26 21:36:29.247 INFO 2368 --- [nio-8002-exec-1] [8a59cb96-bbc8-42a9-aa62-df7a52875447] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 2019-12-26 21:36:35.279 INFO 2368 --- [ async-pool-1] [8a59cb96-bbc8-42a9-aa62-df7a52875447] com.alan.trace.b.BService : send msg by spring success 2019-12-26 21:36:35.283 INFO 2368 --- [pool-1-thread-1] [8a59cb96-bbc8-42a9-aa62-df7a52875447] com.alan.trace.b.BService : send msg by thread pool success

可以看到，A服务成功生成了traceId，并且传递给了B服务，且B服务线程间可以保证同一个请求的traceId是可以传递的。