Spring Cloud Sleuth是一個在應(yīng)用中實現(xiàn)日志跟蹤的強有力的工具嗅义。使用Sleuth庫可以應(yīng)用于計劃任務(wù) 续扔、多線程服務(wù)或復(fù)雜的Web請求悬包，尤其是在一個由多個服務(wù)組成的系統(tǒng)中铭若。當(dāng)我們在這些應(yīng)用中來診斷問題時枫匾，即使有日志記錄也很難判斷出一個請求需要將哪些操作關(guān)聯(lián)在一起灰追。
如果想要診斷復(fù)雜操作堵幽，通常的解決方案是在請求中傳遞唯一的ID到每個方法來識別日志。而Sleuth可以與日志框架Logback弹澎、SLF4J輕松地集成朴下，通過添加獨特的標(biāo)識符來使用日志跟蹤和診斷問題。
1苦蒿、依賴管理
在Spring Boot Web應(yīng)用中增加Sleuth非常簡單殴胧，只需在pom.xml增加以下的依賴：
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-sleuth</artifactId>
</dependency>
同時添加一個應(yīng)用名稱來識別應(yīng)用程序的日志，在配置文件application.properties file增加一行
spring.application.name=Sleuth Tutorial
2、一個簡單的WEB應(yīng)用
首先創(chuàng)建一個服務(wù)
@Service
public class SleuthService {
public void doSomeWorkSameSpan() throws InterruptedException {
Thread.sleep(1000L);
logger.info("Doing some work");
}
}
然后寫一個controller去調(diào)用這個服務(wù)
@RestController
public class SleuthController {
@Autowired
private final SleuthService sleuthService;
@GetMapping("/same-span")
public String helloSleuthSameSpan() throws InterruptedException {
logger.info("Same Span");
sleuthService.doSomeWorkSameSpan();
return "success";
}
}
啟動應(yīng)用团滥，訪問 http://localhost:8080/same-span竿屹，查看日志
2018-04-16 16:35:54.151 INFO [Sleuth Tutorial,0afe3e67168fce4f,0afe3e67168fce4f,false] 5968 --- [nio-8080-exec-1] c.p.s.cloud.sleuth.SleuthController : Same Span
2018-04-16 16:35:55.161 INFO [Sleuth Tutorial,0afe3e67168fce4f,0afe3e67168fce4f,false] 5968 --- [nio-8080-exec-1] c.p.spring.cloud.sleuth.SleuthService : Doing some work
日志的格式為：[application name, traceId, spanId, export]
- application name — 應(yīng)用的名稱，也就是application.properties中的spring.application.name參數(shù)配置的屬性灸姊。
- traceId — 為一個請求分配的ID號拱燃，用來標(biāo)識一條請求鏈路。
- spanId — 表示一個基本的工作單元力惯，一個請求可以包含多個步驟碗誉，每個步驟都擁有自己的spanId。一個請求包含一個TraceId父晶，多個SpanId
- export — 布爾類型哮缺。表示是否要將該信息輸出到類似Zipkin這樣的聚合器進行收集和展示。
可以看到甲喝，TraceId和SpanId在兩條日志中是相同的尝苇，即使消息來源于兩個不同的類。這就可以在不同的日志通過尋找traceid來識別一個請求俺猿。
3茎匠、異步線程池
添加@Async注解實現(xiàn)異步線程調(diào)用，增加一個配置類來建立線程池
@Configuration
@EnableAsync
public class ThreadConfig extends AsyncConfigurerSupport{
@Autowired
private BeanFactory beanFactory;
@Override
public Executor getAsyncExecutor() {
ThreadPoolTaskExecutor threadPoolTaskExecutor = new ThreadPoolTaskExecutor();
threadPoolTaskExecutor.setCorePoolSize(7);
threadPoolTaskExecutor.setMaxPoolSize(42);
threadPoolTaskExecutor.setQueueCapacity(11);
threadPoolTaskExecutor.setThreadNamePrefix("MyExecutor-");
threadPoolTaskExecutor.initialize();
return new LazyTraceExecutor(beanFactory, threadPoolTaskExecutor);
}
}
在這里我們繼承了AsyncConfigurerSupport指定了具體的異步執(zhí)行器押袍，使用LazyTraceExecutor 確保traceId和spanId正確的傳遞，同時給類加上@EnableAsync 注解凯肋。
然后在服務(wù)里增加一個異步方法：
@Async
public void asyncMethod() throws InterruptedException {
logger.info("Start Async Method");
Thread.sleep(1000L);
logger.info("End Async Method");
}
同時在controller里調(diào)用此服務(wù)
@GetMapping("/async")
public String helloSleuthAsync() throws InterruptedException {
logger.info("Before Async Method Call");
sleuthService.asyncMethod();
logger.info("After Async Method Call");
return "success";
}
訪問http://localhost:8080/async谊惭，查看日志如下：
2018-04-16 16:55:06.859 INFO [Sleuth Tutorial,4bc16602ac8262d5,4bc16602ac8262d5,false] 5968 --- [nio-8080-exec-6] c.p.s.cloud.sleuth.SleuthController : Before Async Method Call
2018-04-16 16:55:06.872 INFO [Sleuth Tutorial,4bc16602ac8262d5,4bc16602ac8262d5,false] 5968 --- [nio-8080-exec-6] c.p.s.cloud.sleuth.SleuthController : After Async Method Call
2018-04-16 16:55:06.905 INFO [Sleuth Tutorial,4bc16602ac8262d5,4d216310c71e9c22,false] 5968 --- [ MyExecutor-1] c.p.spring.cloud.sleuth.SleuthService : Start Async Method
2018-04-16 16:55:07.905 INFO [Sleuth Tutorial,4bc16602ac8262d5,4d216310c71e9c22,false] 5968 --- [ MyExecutor-1] c.p.spring.cloud.sleuth.SleuthService : End Async Method
通過例子可以看到Sleuth將traceId傳入了異步方法并創(chuàng)建了以新的spanId，代表這是同一個請求但進入了另一個處理階段侮东，由一個異步線程來執(zhí)行圈盔。
4、計劃任務(wù)
現(xiàn)在我們來看下Sleuth是怎么在@Scheduled 方法里工作的悄雅，修改ThreadConfig 類是它支持時間調(diào)度驱敲。
@Configuration
@EnableAsync
@EnableScheduling
public class ThreadConfig extends AsyncConfigurerSupport
implements SchedulingConfigurer {
//...
@Override
public void configureTasks(ScheduledTaskRegistrar scheduledTaskRegistrar) {
scheduledTaskRegistrar.setScheduler(schedulingExecutor());
}
@Bean(destroyMethod = "shutdown")
public Executor schedulingExecutor() {
return Executors.newScheduledThreadPool(1);
}
}
我們在這里實現(xiàn)了SchedulingConfigurer 接口并重寫了configureTasks 方法，同時在類上面添加了@EnableScheduling 注解宽闲。
新寫一個調(diào)度服務(wù)众眨，定義了一個每3秒執(zhí)行一次的計劃任務(wù)。
@Service
public class SchedulingService {
private Logger logger = LoggerFactory.getLogger(this.getClass());
private final SleuthService sleuthService;
@Autowired
public SchedulingService(SleuthService sleuthService) {
this.sleuthService = sleuthService;
}
@Scheduled(fixedDelay = 30000)
public void scheduledWork() throws InterruptedException {
logger.info("Start some work from the scheduled task");
sleuthService.asyncMethod();
logger.info("End work from scheduled task");
}
}
重啟應(yīng)用等待任務(wù)的執(zhí)行容诬，觀察日志：
2018-04-16 17:10:20.232 INFO [Sleuth Tutorial,5d891f56b6f18505,5d891f56b6f18505,false] 7936 --- [pool-1-thread-1] c.p.s.cloud.sleuth.SchedulingService : Start some work from the scheduled task
2018-04-16 17:10:20.232 INFO [Sleuth Tutorial,5d891f56b6f18505,5d891f56b6f18505,false] 7936 --- [pool-1-thread-1] c.p.s.cloud.sleuth.SchedulingService : End work from scheduled task
2018-04-16 17:10:20.232 INFO [Sleuth Tutorial,5d891f56b6f18505,abe8b45c36f93be8,false] 7936 --- [ MyExecutor-2] c.p.spring.cloud.sleuth.SleuthService : Start Async Method
2018-04-16 17:10:21.232 INFO [Sleuth Tutorial,5d891f56b6f18505,abe8b45c36f93be8,false] 7936 --- [ MyExecutor-2] c.p.spring.cloud.sleuth.SleuthService : End Async Method
2018-04-16 17:10:50.235 INFO [Sleuth Tutorial,0dd33d0764f0e6db,0dd33d0764f0e6db,false] 7936 --- [pool-1-thread-1] c.p.s.cloud.sleuth.SchedulingService : Start some work from the scheduled task
2018-04-16 17:10:50.235 INFO [Sleuth Tutorial,0dd33d0764f0e6db,0dd33d0764f0e6db,false] 7936 --- [pool-1-thread-1] c.p.s.cloud.sleuth.SchedulingService : End work from scheduled task
2018-04-16 17:10:50.236 INFO [Sleuth Tutorial,0dd33d0764f0e6db,5062d156f65a293e,false] 7936 --- [ MyExecutor-3] c.p.spring.cloud.sleuth.SleuthService : Start Async Method
2018-04-16 17:10:51.236 INFO [Sleuth Tutorial,0dd33d0764f0e6db,5062d156f65a293e,false] 7936 --- [ MyExecutor-3] c.p.spring.cloud.sleuth.SleuthService : End Async Method
在這里可以看到Sleuth為每個任務(wù)實例都創(chuàng)建一個新的traceId和spanId娩梨。
5、總結(jié)
通過本文我們看到Spring Cloud Sleuth可以應(yīng)用在各種各樣的單一Web應(yīng)用中览徒。我們可以使用這項技術(shù)輕松地為一個請求采集日志狈定，即使請求跨越多個線程。幫助我們在多線程環(huán)境下進行清晰的調(diào)試，通過識別traceId和spanId來確定每一個操作和操作中的每一步纽什，這樣可以減輕我們做日志分析的復(fù)雜性措嵌。
除了在單一應(yīng)用外，Spring Cloud Sleuth為微服務(wù)架構(gòu)中的分布式服務(wù)跟蹤問題提供了一套完整的解決方案芦缰∑蟪玻可應(yīng)用于通過RestTemplate發(fā)起的請求，通過Zuul代理傳遞的請求饺藤，通過諸如RabbitMQ包斑、Kafka（或者其他任何Spring Cloud Stream綁定器實現(xiàn)的消息中間件）轉(zhuǎn)遞的請求。
