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

TraceAsyncConfigurer.java

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

@Slf4j@Componentpublic 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) {Map<string, string> contextMap = MDC.getCopyOfContextMap();return () -> {if (contextMap != null) {MDC.setContextMap(contextMap);}try {runnable.run();} finally {MDC.clear();}};}}}

HttpUtils.java

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

@Slf4jpublic 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@RestControllerpublic class AController {@RequestMApping("a")public String a(String name) {log.info("Hello, " + name);try {// A中调用Breturn 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@RestControllerpublic class BController {@Autowiredprivate BService bService;@RequestMapping("b")public String b() {log.info("Hello, b receive request from a");bService.sendMsgBySpring();bService.sendMsgByThreadPool();return "ok";}}

BService.java

@Slf4j@Servicepublic class BService {public static final TraceThreadPoolExecutor threadPool = new TraceThreadPoolExecutor(5, 5, 60, TimeUnit.SECONDS, new LinkedBlockingQueue<>(100));@Asyncpublic 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'

测试打开浏览器，输入http://localhost:8001/a?name=andy 。
A服务输出日志：

2019-12-26 21:36:29.132INFO 5132 --- [nio-8001-exec-2] [8a59cb96-bbc8-42a9-aa62-df7a52875447] com.alan.trace.a.AController: Hello, andy2019-12-26 21:36:35.380INFO 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.244INFO 2368 --- [nio-8002-exec-1] [8a59cb96-bbc8-42a9-aa62-df7a52875447] com.alan.trace.b.BController: Hello, b receive request from a2019-12-26 21:36:29.247INFO 2368 --- [nio-8002-exec-1] [8a59cb96-bbc8-42a9-aa62-df7a52875447] o.s.s.concurrent.ThreadPoolTaskExecutor: Initializing ExecutorService2019-12-26 21:36:35.279INFO 2368 --- [async-pool-1] [8a59cb96-bbc8-42a9-aa62-df7a52875447] com.alan.trace.b.BService: send msg by spring success2019-12-26 21:36:35.283INFO 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是可以传递的。