通過(guò)上一篇《分布式服務(wù)跟蹤（入門(mén)）》的例子，我們已經(jīng)通過(guò)Spring Cloud Sleuth往微服務(wù)應(yīng)用中添加了實(shí)現(xiàn)分布式跟蹤具備的基本要素。下面通過(guò)本文來(lái)詳細(xì)說(shuō)說(shuō)實(shí)現(xiàn)分布式服務(wù)跟蹤的一些要點(diǎn)。

分布式系統(tǒng)中的服務(wù)跟蹤在理論上并不復(fù)雜，它主要包括下面兩個(gè)關(guān)鍵點(diǎn)：

• 為了實(shí)現(xiàn)請(qǐng)求跟蹤，當(dāng)請(qǐng)求發(fā)送到分布式系統(tǒng)的入口端點(diǎn)時(shí)，只需要服務(wù)跟蹤框架為該請(qǐng)求創(chuàng)建一個(gè)***的跟蹤標(biāo)識(shí)，同時(shí)在分布式系統(tǒng)內(nèi)部流轉(zhuǎn)的時(shí)候，框架始終保持傳遞該***標(biāo)識(shí)，直到返回給請(qǐng)求方為止，這個(gè)***標(biāo)識(shí)就是前文中提到的Trace ID。通過(guò)Trace ID的記錄，我們就能將所有請(qǐng)求過(guò)程日志關(guān)聯(lián)起來(lái)。
• 為了統(tǒng)計(jì)各處理單元的時(shí)間延遲，當(dāng)請(qǐng)求達(dá)到各個(gè)服務(wù)組件時(shí)，或是處理邏輯到達(dá)某個(gè)狀態(tài)時(shí)，也通過(guò)一個(gè)***標(biāo)識(shí)來(lái)標(biāo)記它的開(kāi)始、具體過(guò)程以及結(jié)束，該標(biāo)識(shí)就是我們前文中提到的Span ID，對(duì)于每個(gè)Span來(lái)說(shuō)，它必須有開(kāi)始和結(jié)束兩個(gè)節(jié)點(diǎn)，通過(guò)記錄開(kāi)始Span和結(jié)束Span的時(shí)間戳，就能統(tǒng)計(jì)出該Span的時(shí)間延遲，除了時(shí)間戳記錄之外，它還可以包含一些其他元數(shù)據(jù)，比如：事件名稱、請(qǐng)求信息等。

[[222355]]

在快速入門(mén)示例中，我們輕松實(shí)現(xiàn)了日志級(jí)別的跟蹤信息接入，這完全歸功于spring-cloud-starter-sleuth組件的實(shí)現(xiàn)。在Spring Boot應(yīng)用中，通過(guò)在工程中引入spring-cloud-starter-sleuth依賴之后， 它會(huì)自動(dòng)的為當(dāng)前應(yīng)用構(gòu)建起各通信通道的跟蹤機(jī)制，比如：

• 通過(guò)諸如RabbitMQ、Kafka（或者其他任何Spring Cloud Stream綁定器實(shí)現(xiàn)的消息中間件）傳遞的請(qǐng)求
• 通過(guò)Zuul代理傳遞的請(qǐng)求
• 通過(guò)RestTemplate發(fā)起的請(qǐng)求

在快速入門(mén)示例中，由于trace-1對(duì)trace-2發(fā)起的請(qǐng)求是通過(guò)RestTemplate實(shí)現(xiàn)的，所以spring-cloud-starter-sleuth組件會(huì)對(duì)該請(qǐng)求進(jìn)行處理，在發(fā)送到trace-2之前sleuth會(huì)為在該請(qǐng)求的Header中增加實(shí)現(xiàn)跟蹤需要的重要信息，主要有下面這幾個(gè)（更多關(guān)于頭信息的定義我們可以通過(guò)查看org.springframework.cloud.sleuth.Span的源碼獲?。?/p>

• X-B3-TraceId：一條請(qǐng)求鏈路（Trace）的***標(biāo)識(shí)，必須值
• X-B3-SpanId：一個(gè)工作單元（Span）的***標(biāo)識(shí)，必須值
• X-B3-ParentSpanId:：標(biāo)識(shí)當(dāng)前工作單元所屬的上一個(gè)工作單元，Root Span（請(qǐng)求鏈路的***個(gè)工作單元）的該值為空
• X-B3-Sampled：是否被抽樣輸出的標(biāo)志，1表示需要被輸出，0表示不需要被輸出
• X-Span-Name：工作單元的名稱

我們可以通過(guò)對(duì)trace-2的實(shí)現(xiàn)做一些修改來(lái)輸出這些頭部信息，具體如下：

@RequestMapping(value = "/trace-2", method = RequestMethod.GET) 
public String trace(HttpServletRequest request) { 
    logger.info("===<call trace-2, TraceId={}, SpanId={}>===", 
            request.getHeader("X-B3-TraceId"), request.getHeader("X-B3-SpanId")); 
    return "Trace"; 
} 

通過(guò)上面的改造，我們?cè)龠\(yùn)行快速入門(mén)的示例內(nèi)容，并發(fā)起對(duì)trace-1的接口訪問(wèn)，我們可以得到如下輸出內(nèi)容。其中在trace-2的控制臺(tái)中，輸出了當(dāng)前正在處理的TraceID和SpanId信息。

-- trace-1 
INFO [trace-1,a6e9175ffd5d2c88,8524f519b8a9e399,true] 10532 --- [nio-9101-exec-2] icationEnhancerBySpringCGLIB27aa9624 : ===<call trace-1>=== 
 
-- trace-2 
INFO [trace-2,a6e9175ffd5d2c88,ce60dcf1e2ed918f,true] 1208 --- [nio-9102-exec-3] icationEnhancerBySpringCGLIBa7d84797 : ===<call trace-2, TraceId=a6e9175ffd5d2c88, SpanId=be4949ec115e554e>=== 

為了更直觀的觀察跟蹤信息，我們還可以在application.properties中增加下面的配置：

logging.level.org.springframework.web.servlet.DispatcherServlet=DEBUG 

通過(guò)將Spring MVC的請(qǐng)求分發(fā)日志級(jí)別調(diào)整為DEBUG級(jí)別，我們可以看到更多跟蹤信息：

-- trace-1 
2016-11-27 09:26:52.663 DEBUG [trace-1,a6e9175ffd5d2c88,a6e9175ffd5d2c88,true] 10532 --- [nio-9101-exec-2] o.s.web.servlet.DispatcherServlet        : DispatcherServlet with name 'dispatcherServlet' processing GET request for [/trace-1] 
2016-11-27 09:26:52.666 DEBUG [trace-1,a6e9175ffd5d2c88,a6e9175ffd5d2c88,true] 10532 --- [nio-9101-exec-2] o.s.web.servlet.DispatcherServlet        : Last-Modified value for [/trace-1] is: -1 
2016-11-27 09:26:52.685 DEBUG [trace-1,a6e9175ffd5d2c88,8524f519b8a9e399,true] 10532 --- [nio-9101-exec-2] o.s.web.servlet.DispatcherServlet        : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling 
2016-11-27 09:26:52.685 DEBUG [trace-1,a6e9175ffd5d2c88,a6e9175ffd5d2c88,true] 10532 --- [nio-9101-exec-2] o.s.web.servlet.DispatcherServlet        : Successfully completed request 
 
-- trace-2 
2016-11-27 09:26:52.673 DEBUG [trace-2,a6e9175ffd5d2c88,be4949ec115e554e,true] 1208 --- [nio-9102-exec-3] o.s.web.servlet.DispatcherServlet        : DispatcherServlet with name 'dispatcherServlet' processing GET request for [/trace-2] 
2016-11-27 09:26:52.679 DEBUG [trace-2,a6e9175ffd5d2c88,be4949ec115e554e,true] 1208 --- [nio-9102-exec-3] o.s.web.servlet.DispatcherServlet        : Last-Modified value for [/trace-2] is: -1 
2016-11-27 09:26:52.682 DEBUG [trace-2,a6e9175ffd5d2c88,ce60dcf1e2ed918f,true] 1208 --- [nio-9102-exec-3] o.s.web.servlet.DispatcherServlet        : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling 
2016-11-27 09:26:52.683 DEBUG [trace-2,a6e9175ffd5d2c88,be4949ec115e554e,true] 1208 --- [nio-9102-exec-3] o.s.web.servlet.DispatcherServlet        : Successfully completed request 

本文完整示例：

讀者可以根據(jù)喜好選擇下面的兩個(gè)倉(cāng)庫(kù)中查看trace-1和trace-2兩個(gè)項(xiàng)目：

Github：https://github.com/dyc87112/SpringCloud-Learning/

Gitee：https://gitee.com/didispace/SpringCloud-Learning/

【本文為51CTO專欄作者“翟永超”的原創(chuàng)稿件，轉(zhuǎn)載請(qǐng)通過(guò)51CTO聯(lián)系作者獲取授權(quán)】

戳這里，看該作者更多好文