1.新建項目java
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
<!--lombok-->
<dependency>
<groupId>org.projectlombok</groupId>
<artifactId>lombok</artifactId>
<optional>true</optional>
</dependency>
複製代碼
除了spring的web依賴包外,添加一個lombok,方便編碼。web
2.編寫controller方法spring
@RestController
public class TestController {
@GetMapping("hello")
public String hello(){
log.info("this is hello 1");
log.info("this is hello 2");
log.info("this is hello 3");
return "hello";
}
}
複製代碼
這個時候一個簡單的rest接口已經完成了,咱們能夠先看看日誌的效果。bash
2019-10-23 10:45:10.917 INFO 1146 --- [nio-8080-exec-1] c.e.demo.controller.TestController : this is hello 1
2019-10-23 10:45:10.917 INFO 1146 --- [nio-8080-exec-1] c.e.demo.controller.TestController : this is hello 2
2019-10-23 10:45:10.917 INFO 1146 --- [nio-8080-exec-1] c.e.demo.controller.TestController : this is hello 3
複製代碼
從這個日誌中,咱們根本沒法區分單獨的請求。若是同一時間有2到3個請求過來的話,那麼你還能分得清那個對那個麼?因此這就是今天要改造的地方。app
其實要改造的話其實很簡單,咱們能夠在每一個controller入口處,生成惟一的uuid,並傳遞下去。這樣的話缺點就是對代碼干擾太大,每一個方法都要多加一個參數。框架
那麼咱們能不能把這個參數存在一個統一的地方,須要打印日誌的時候,直接去取呢?你們應該能夠想到了,用ThreadLocal類。其實到這兒思路已經對了,不過日誌框架也想到了這個問題,他們已經封裝好了現成的功能,就是日誌框架中的MDCdom
1.首先將日誌的id添加進MDC中異步
@Component
public class TraceIdInterceptor extends HandlerInterceptorAdapter {
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
String traceId = getTraceId(request);
MDC.put("traceId", traceId);
//將traceId添加進響應頭
response.addHeader("traceId",traceId);
return true;
}
private String getTraceId(HttpServletRequest request){
return String.format("%s - %s",request.getRequestURI(), UUID.randomUUID());
}
}
@Component
public class GlobalWebMvcConfigurer implements WebMvcConfigurer {
@Autowired
private TraceIdInterceptor traceIdInterceptor;
@Override
/*
traceId 攔截器須要在最開始執行
*/
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(traceIdInterceptor).order(0);
}
}
複製代碼
咱們使用一下Spring的攔截器功能。在請求開始以前,將請求id添加進MDC。async
2.修改日誌的配置文件ide
新建一個logback-spring.xml文件添加以下內容
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<property name="LOG_PATTERN"
value="%d{yyyy-MM-dd} %d{HH:mm:ss.SSS} [%-5level] [%X{traceId}] [%thread] %logger{36} %F.%L %msg%n">
</property>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>${LOG_PATTERN}</pattern>
</encoder>
<!-- 控制檯打印INFO及以上級別的日誌 -->
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>INFO</level>
</filter>
</appender>
<root>
<appender-ref ref="STDOUT"/>
</root>
</configuration>
複製代碼
在日誌的格式LOG_PATTERN中,添加%X{traceId} ,這樣日誌在打印的時候便會去MDC中取出traceid,放在這兒。如今咱們能夠看看效果。
2019-10-23 11:02:46.649 [INFO ] [/hello - 79ec561a-ef5e-4dc5-91cc-b2143fa3dbd3] [http-nio-8080-exec-1] c.e.demo.controller.TestController TestController.java.18 this is hello 1
2019-10-23 11:02:46.649 [INFO ] [/hello - 79ec561a-ef5e-4dc5-91cc-b2143fa3dbd3] [http-nio-8080-exec-1] c.e.demo.controller.TestController TestController.java.19 this is hello 2
2019-10-23 11:02:46.650 [INFO ] [/hello - 79ec561a-ef5e-4dc5-91cc-b2143fa3dbd3] [http-nio-8080-exec-1] c.e.demo.controller.TestController TestController.java.20 this is hello 3
2019-10-23 11:02:47.612 [INFO ] [/hello - 2ac7450f-40f5-441c-8e10-9b937c006484] [http-nio-8080-exec-2] c.e.demo.controller.TestController TestController.java.18 this is hello 1
2019-10-23 11:02:47.612 [INFO ] [/hello - 2ac7450f-40f5-441c-8e10-9b937c006484] [http-nio-8080-exec-2] c.e.demo.controller.TestController TestController.java.19 this is hello 2
2019-10-23 11:02:47.612 [INFO ] [/hello - 2ac7450f-40f5-441c-8e10-9b937c006484] [http-nio-8080-exec-2] c.e.demo.controller.TestController TestController.java.20 this is hello 3
複製代碼
能夠看到,兩個請求經過traceId能夠很清楚的區分開了。這樣咱們在排查問題的時候,能夠經過響應頭裏面的traceId,直接查找到相關日誌,很是方便。
以前說過traceId的實現思路是經過ThreadLocal來實現的。使用ThreadLocal有一個前提就是一個請求進來始終是一個線程在處理。若是用到spring中的異步方法,traceId就會失效了。
咱們能夠作個實驗
//編寫一個service類
public class Service {
@Async
public void run(){
log.info("this is service run!");
}
}
//在hello方法中調用service的run方法
@GetMapping("hello")
public String hello(){
log.info("this is hello 1");
log.info("this is hello 2");
log.info("this is hello 3");
service.run();
return "hello";
}
複製代碼
能夠看的打印出來的日誌
2019-10-23 11:12:23.265 [INFO ] [/hello - 96b31833-e8e6-46c5-8459-d423309d1488] [http-nio-8080-exec-1] c.e.demo.controller.TestController TestController.java.22 this is hello 1
2019-10-23 11:12:23.266 [INFO ] [/hello - 96b31833-e8e6-46c5-8459-d423309d1488] [http-nio-8080-exec-1] c.e.demo.controller.TestController TestController.java.23 this is hello 2
2019-10-23 11:12:23.267 [INFO ] [/hello - 96b31833-e8e6-46c5-8459-d423309d1488] [http-nio-8080-exec-1] c.e.demo.controller.TestController TestController.java.24 this is hello 3
2019-10-23 11:12:23.278 [INFO ] [] [task-1] com.example.demo.controller.Service Service.java.17 this is service run!
複製代碼
其實也很簡單,只要對異步線程池跑的對象稍做封裝便可。
@EnableAsync
@Configuration
public class AsyncConfiguration {
@Autowired
private AppConfig config;
@Bean("async")
public Executor taskExecutor() {
ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
//設置核心線程數量
executor.setCorePoolSize(config.getAsync().getCorePoolSize());
//設置最大線程數量
executor.setMaxPoolSize(config.getAsync().getMaxPoolSize());
//設置隊列最大長度
executor.setQueueCapacity(config.getAsync().getQueueCapacity());
//設置線程空閒時間
executor.setKeepAliveSeconds(config.getAsync().getKeepLiveSeconds());
//設置線程前綴
executor.setThreadNamePrefix("async-");
//設置拒絕策略
executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
//設置線程裝飾器
executor.setTaskDecorator(runnable -> ThreadMdcUtils.wrapAsync(runnable, MDC.getCopyOfContextMap()));
return executor;
}
}
public class ThreadMdcUtils {
public static Runnable wrapAsync(Runnable task, Map<String,String> context){
return () -> {
if(context==null){
MDC.clear();
}else {
MDC.setContextMap(context);
}
if(MDC.get(Constant.TraceId)==null){
MDC.put(Constant.TraceId,UUIDUtils.randomUUID());
}
try {
task.run();
}finally {
MDC.clear();
}
};
}
}
複製代碼
這樣的話,即使調用異步方法,也能得到統一的日誌id。