在本節(jié)內(nèi)容之前镐捧，我們已經(jīng)對如何引入Sleuth跟蹤信息和搭建Zipkin服務(wù)端分析跟蹤延遲的過程做了詳細(xì)的介紹，相信大家對于Sleuth和Zipkin已經(jīng)有了一定的感性認(rèn)識卸勺。接下來，我們介紹一下關(guān)于Zipkin收集跟蹤信息的過程細(xì)節(jié)，以幫助我們更好地理解Sleuth生產(chǎn)跟蹤信息以及輸出跟蹤信息的整體過程和工作原理逻族。
原文地址：http://blog.didispace.com/spring-cloud-starter-dalston-8-5/
數(shù)據(jù)模型
我們先來看看Zipkin中關(guān)于跟蹤信息的一些基礎(chǔ)概念。由于Zipkin的實(shí)現(xiàn)借鑒了Google的Dapper骄崩，所以它們有著類似的核心術(shù)語聘鳞，主要有下面幾個(gè)內(nèi)容：
Span：它代表了一個(gè)基礎(chǔ)的工作單元。我們以HTTP請求為例要拂，一次完整的請求過程在客戶端和服務(wù)端都會產(chǎn)生多個(gè)不同的事件狀態(tài)（比如下面所說的四個(gè)核心Annotation所標(biāo)識的不同階段）抠璃，對于同一個(gè)請求來說，它們屬于一個(gè)工作單元脱惰，所以同一HTTP請求過程中的四個(gè)Annotation同屬于一個(gè)Span搏嗡。每一個(gè)不同的工作單元都通過一個(gè)64位的ID來唯一標(biāo)識，稱為Span ID拉一。另外采盒，在工作單元中還存儲了一個(gè)用來串聯(lián)其他工作單元的ID，它也通過一個(gè)64位的ID來唯一標(biāo)識蔚润，稱為Trace ID磅氨。在同一條請求鏈路中的不同工作單元都會有不同的Span ID，但是它們的Trace ID是相同的抽碌，所以通過Trace ID可以將一次請求中依賴的所有依賴請求串聯(lián)起來形成請求鏈路悍赢。除了這兩個(gè)核心的ID之外，Span中還存儲了一些其他信息货徙，比如：描述信息左权、事件時(shí)間戳、Annotation的鍵值對屬性痴颊、上一級工作單元的Span ID等赏迟。Trace：它是由一系列具有相同Trace ID的Span串聯(lián)形成的一個(gè)樹狀結(jié)構(gòu)。在復(fù)雜的分布式系統(tǒng)中蠢棱，每一個(gè)外部請求通常都會產(chǎn)生一個(gè)復(fù)雜的樹狀結(jié)構(gòu)的Trace锌杀。-
Annotation：它用來及時(shí)地記錄一個(gè)事件的存在。我們可以把Annotation理解為一個(gè)包含有時(shí)間戳的事件標(biāo)簽泻仙，對于一個(gè)HTTP請求來說糕再，在Sleuth中定義了下面四個(gè)核心Annotation來標(biāo)識一個(gè)請求的開始和結(jié)束：-
cs（Client Send）：該Annotation用來記錄客戶端發(fā)起了一個(gè)請求，同時(shí)它也標(biāo)識了這個(gè)HTTP請求的開始玉转。 -
sr（Server Received）：該Annotation用來記錄服務(wù)端接收到了請求突想，并準(zhǔn)備開始處理它。通過計(jì)算sr與cs兩個(gè)Annotation的時(shí)間戳之差，我們可以得到當(dāng)前HTTP請求的網(wǎng)絡(luò)延遲猾担。 -
ss（Server Send）：該Annotation用來記錄服務(wù)端處理完請求后準(zhǔn)備發(fā)送請求響應(yīng)信息袭灯。通過計(jì)算ss與sr兩個(gè)Annotation的時(shí)間戳之差，我們可以得到當(dāng)前服務(wù)端處理請求的時(shí)間消耗绑嘹。 -
cr（Client Received）：該Annotation用來記錄客戶端接收到服務(wù)端的回復(fù)稽荧，同時(shí)它也標(biāo)識了這個(gè)HTTP請求的結(jié)束。通過計(jì)算cr與cs兩個(gè)Annotation的時(shí)間戳之差工腋，我們可以得到該HTTP請求從客戶端發(fā)起開始到接收服務(wù)端響應(yīng)的總時(shí)間消耗姨丈。
-
BinaryAnnotation：它用來對跟蹤信息添加一些額外的補(bǔ)充說明，一般以鍵值對方式出現(xiàn)夷蚊。比如：在記錄HTTP請求接收后執(zhí)行具體業(yè)務(wù)邏輯時(shí)构挤，此時(shí)并沒有默認(rèn)的Annotation來標(biāo)識該事件狀態(tài)髓介，但是有BinaryAnnotation信息對其進(jìn)行補(bǔ)充惕鼓。
收集機(jī)制
在理解了Zipkin的各個(gè)基本概念之后，下面我們結(jié)合前面章節(jié)中實(shí)現(xiàn)的例子來詳細(xì)介紹和理解Spring Cloud Sleuth是如何對請求調(diào)用鏈路完成跟蹤信息的生產(chǎn)唐础、輸出和后續(xù)處理的箱歧。
首先，我們來看看Sleuth在請求調(diào)用時(shí)是怎么樣來記錄和生成跟蹤信息的一膨。下圖展示了我們在本章節(jié)中實(shí)現(xiàn)示例的運(yùn)行全過程：客戶端發(fā)送了一個(gè)HTTP請求到trace-1呀邢，trace-1依賴于trace-2的服務(wù)，所以trace-1再發(fā)送一個(gè)HTTP請求到trace-2豹绪，待trace-2返回響應(yīng)之后价淌，trace-1再組織響應(yīng)結(jié)果返回給客戶端。
在上圖的請求過程中瞒津，我們?yōu)檎麄€(gè)調(diào)用過程標(biāo)記了10個(gè)標(biāo)簽蝉衣，它們分別代表了該請求鏈路運(yùn)行過程中記錄的幾個(gè)重要事件狀態(tài)，我們根據(jù)事件發(fā)生的時(shí)間順序我們?yōu)檫@些標(biāo)簽做了從小到大的編號巷蚪，1代表請求的開始病毡、10代表請求的結(jié)束。每個(gè)標(biāo)簽中記錄了一些我們上面提到過的核心元素：Trace ID屁柏、Span ID以及Annotation啦膜。由于這些標(biāo)簽都源自一個(gè)請求，所以他們的Trace ID相同淌喻，而標(biāo)簽1和標(biāo)簽10是起始和結(jié)束節(jié)點(diǎn)僧家，它們的Trace ID與Span ID是相同的。
根據(jù)Span ID裸删，我們可以發(fā)現(xiàn)在這些標(biāo)簽中一共產(chǎn)生了4個(gè)不同ID的Span八拱，這4個(gè)Span分別代表了這樣4個(gè)工作單元：
- Span T：記錄了客戶端請求到達(dá)
trace-1和trace-1發(fā)送請求響應(yīng)的兩個(gè)事件，它可以計(jì)算出了客戶端請求響應(yīng)過程的總延遲時(shí)間。 - Span A：記錄了
trace-1應(yīng)用在接收到客戶端請求之后調(diào)用處理方法的開始和結(jié)束兩個(gè)事件乘粒，它可以計(jì)算出trace-1應(yīng)用用于處理客戶端請求時(shí)豌注，內(nèi)部邏輯花費(fèi)的時(shí)間延遲。 - Span B：記錄了
trace-1應(yīng)用發(fā)送請求給trace-2應(yīng)用灯萍、trace-2應(yīng)用接收請求轧铁，trace-2應(yīng)用發(fā)送響應(yīng)、trace-1應(yīng)用接收響應(yīng)四個(gè)事件旦棉，它可以計(jì)算出trace-1調(diào)用trace-2的總體依賴時(shí)間（cr - cs）齿风，也可以計(jì)算出trace-1到trace-2的網(wǎng)絡(luò)延遲（sr - cs），也可以計(jì)算出trace-2應(yīng)用用于處理客戶端請求的內(nèi)部邏輯花費(fèi)的時(shí)間延遲（ss - sr）绑洛。 - Span C：記錄了
trace-2應(yīng)用在接收到trace-1的請求之后調(diào)用處理方法的開始和結(jié)束兩個(gè)事件救斑，它可以計(jì)算出trace-2應(yīng)用用于處理來自trace-1的請求時(shí)，內(nèi)部邏輯花費(fèi)的時(shí)間延遲真屯。
在圖中展現(xiàn)的這個(gè)4個(gè)Span正好對應(yīng)了Zipkin查看跟蹤詳細(xì)頁面中的顯示內(nèi)容脸候，它們的對應(yīng)關(guān)系如下圖所示：
仔細(xì)的讀者可能還有這樣一個(gè)疑惑：我們在Zipkin服務(wù)端查詢跟蹤信息時(shí)（如下圖所示），在查詢結(jié)果頁面中顯示的spans是5绑蔫，而點(diǎn)擊進(jìn)入跟蹤明細(xì)頁面時(shí)运沦，顯示的Total Spans又是4，為什么會出現(xiàn)span數(shù)量不一致的情況呢配深？
實(shí)際上這兩邊的span數(shù)量內(nèi)容有不同的含義携添，在查詢結(jié)果頁面中的5 spans代表了總共接收的Span數(shù)量，而在詳細(xì)頁面中的Total Span則是對接收Span進(jìn)行合并后的結(jié)果篓叶，也就是前文中我們介紹的4個(gè)不同ID的Span內(nèi)容烈掠。下面我們來詳細(xì)研究一下Zipkin服務(wù)端收集客戶端跟蹤信息的過程，看看它到底收到了哪些具體的Span內(nèi)容缸托，從而來理解Zipkin中收集到的Span總數(shù)量左敌。
為了更直觀的觀察Zipkin服務(wù)端的收集過程，我們可以對之前實(shí)現(xiàn)的消息中間件方式收集跟蹤信息的程序進(jìn)行調(diào)試嗦董。通過在Zipkin服務(wù)端的消息通道監(jiān)聽程序中增加斷點(diǎn)母谎，我們就能清楚的知道客戶端都發(fā)送了一些什么信息到Zipkin的服務(wù)端。在spring-cloud-sleuth-zipkin-stream依賴包中的代碼并不多京革，我們很容易的就能找到定義消息通道監(jiān)聽的實(shí)現(xiàn)類：org.springframework.cloud.sleuth.zipkin.stream.ZipkinMessageListener奇唤。它的具體實(shí)現(xiàn)如下所示，其中SleuthSink.INPUT定義了監(jiān)聽的輸入通道匹摇，默認(rèn)會使用名為sleuth的主題咬扇，我們也可以通過Spring Cloud Stream的配置對其進(jìn)行修改。
@MessageEndpoint
@Conditional(NotSleuthStreamClient.class)
public class ZipkinMessageListener {
final Collector collector;
@ServiceActivator(inputChannel = SleuthSink.INPUT)
public void sink(Spans input) {
List<zipkin.Span> converted = ConvertToZipkinSpanList.convert(input);
this.collector.accept(converted, Callback.NOOP);
}
...
}
從通道監(jiān)聽方法的定義中我們可以看到Sleuth與Zipkin在整合的時(shí)候是有兩個(gè)不同的Span定義的廊勃，一個(gè)是消息通道的輸入對象org.springframework.cloud.sleuth.stream.Spans懈贺，它是sleuth中定義的用于消息通道傳輸?shù)腟pan對象经窖，每個(gè)消息中包含的Span信息定義在org.springframework.cloud.sleuth.Span對象中，但是真正在zipkin服務(wù)端使用的并非這個(gè)Span對象梭灿，而是zipkin自己的zipkin.Span對象画侣。所以，在消息通道監(jiān)聽處理方法中堡妒，對sleuth的Span做了處理配乱，每次接收到sleuth的Span之后就將其轉(zhuǎn)換成Zipkin的Span。
下面我們可以嘗試在sink(Spans input)方法實(shí)現(xiàn)的第一行代碼中加入斷點(diǎn)皮迟，并向trace-1發(fā)送一個(gè)請求搬泥，觸發(fā)跟蹤信息發(fā)送到RabbitMQ上。此時(shí)我們通過DEBUG模式可以發(fā)現(xiàn)消息通道中都接收到了兩次輸入伏尼，一次來自trace-1忿檩，一次來自trace-2。下面兩張圖分別展示了來自trace-1和trace-2輸出的跟蹤消息爆阶，其中trace-1的跟蹤消息包含了3條span信息燥透，trace-2的跟蹤消息包含了2條span信息，所以在這個(gè)請求調(diào)用鏈上扰她，一共發(fā)送了5個(gè)span信息兽掰，也就是我們在Zipkin搜索結(jié)果頁面中看到的spans數(shù)量信息。
點(diǎn)開一個(gè)具體的Span內(nèi)容徒役，我們可以看到如下所示的結(jié)構(gòu)，它記錄了Sleuth中定義的Span詳細(xì)信息窖壕，包括該Span的開始時(shí)間忧勿、結(jié)束時(shí)間、Span的名稱瞻讽、Trace ID鸳吸、Span ID、Tags（對應(yīng)Zipkin中的BinaryAnnotation）速勇、Logs（對應(yīng)Zipkin中的Annotation）等我們之前提到過的核心跟蹤信息晌砾。
介紹到這里仔細(xì)的讀者可能會有一個(gè)這樣的疑惑，在明細(xì)信息中展示的Trace ID和Span ID的值為什么與列表展示的概要信息中的Trace ID和Span ID的值不一樣呢烦磁？實(shí)際上养匈，Trace ID和Span ID都是使用long類型存儲的，在DEBUG模式下查看其明細(xì)時(shí)自然是long類型都伪，也就是它的原始值呕乎，但是在查看Span對象的時(shí)候，我們看到的是通過toString()函數(shù)處理過的值陨晶，從sleuth的Span源碼中我們可以看到如下定義猬仁，在輸出Trace ID和Span ID時(shí)都調(diào)用了idToHex函數(shù)將long類型的值轉(zhuǎn)換成了16進(jìn)制的字符串值，所以在DEBUG時(shí)我們會看到兩個(gè)不一樣的值。
public String toString() {
return "[Trace: " + idToHex(this.traceId) + ", Span: " + idToHex(this.spanId)
+ ", Parent: " + getParentIdIfPresent() + ", exportable:" + this.exportable + "]";
}
public static String idToHex(long id) {
return Long.toHexString(id);
}
在接收到Sleuth之后我們將程序繼續(xù)執(zhí)行下去湿刽，可以看到經(jīng)過轉(zhuǎn)換后的Zipkin的Span內(nèi)容的烁，它們保存在一個(gè)名為converted的列表中，具體內(nèi)容如下所示：
上圖展示了轉(zhuǎn)換后的Zipkin Span對象的詳細(xì)內(nèi)容诈闺，我們可以看到很多熟悉的名稱撮躁，也就是之前我們介紹的關(guān)于zipkin中的各個(gè)基本概念，而這些基本概念的值我們也都可以在之前sleuth的原始span中找到买雾，其中annotations和binaryAnnotations有一些特殊把曼，在sleuth定義的span中沒有使用相同的名稱，而是使用了logs和tags來命名漓穿。從這里的詳細(xì)信息中嗤军，我們可以直觀的看到annotations和binaryAnnotations的作用，其中annotations中存儲了當(dāng)前Span包含的各種事件狀態(tài)以及對應(yīng)事件狀態(tài)的時(shí)間戳晃危，而binaryAnnotations則存儲了對事件的補(bǔ)充信息叙赚，比如上圖中存儲的就是該HTTP請求的細(xì)節(jié)描述信息，除此之外僚饭，它也可以存儲對調(diào)用函數(shù)的詳細(xì)描述（如下圖所示）震叮。
下面我們再來詳細(xì)看看通過調(diào)試消息監(jiān)聽程序接收到的這5個(gè)Span內(nèi)容。首先鳍鸵，我們可以發(fā)現(xiàn)每個(gè)Span中都包含有3個(gè)ID信息苇瓣，其中除了標(biāo)識Span自身的ID以及用來標(biāo)識整條鏈路的traceId之外，還有一個(gè)之前沒有提過的parentId偿乖，它是用來標(biāo)識各Span父子關(guān)系的ID（它的值來自與上一步執(zhí)行單元Span的ID） 击罪，通過parentId的定義我們可以為每個(gè)Span找到它的前置節(jié)點(diǎn)，從而定位每個(gè)Span在請求調(diào)用鏈中的確切位置贪薪。在每條調(diào)用鏈路中都有一個(gè)特殊的Span媳禁，它的parentId為null，這類Span我們稱它為Root Span画切，也就是這條請求調(diào)用鏈的根節(jié)點(diǎn)竣稽。為了弄清楚這些Span之間的關(guān)系，我們可以從Root Span開始來整理出整條鏈路的Span內(nèi)容霍弹。下表展示了我們從Root Span開始毫别，根據(jù)各個(gè)Span的父子關(guān)系最后整理出的結(jié)果：
| Host | Span ID | Parent Span ID | Annotation | Binary Annotation |
|---|---|---|---|---|
| trace-1 | e9a933ec50d180d6 | null | [sr, ss] | |
| trace-1 | c48122fa096bffe8 | e9a933ec50d180d6 | [trace-1,TraceApplication,trace] | |
| trace-1 | 1ae2e9a317faa422 | c48122fa096bffe8 | [cs, cr] | |
| trace-2 | 1ae2e9a317faa422 | c48122fa096bffe8 | [sr, ss] | |
| trace-2 | 36194e4182985c4e | 1ae2e9a317faa422 | [trace-2,TraceApplication,trace] |
上表中的Host代表了該Span是從哪個(gè)應(yīng)用發(fā)送過來的；Span ID是當(dāng)前Span的唯一標(biāo)識庞萍；Parent Span ID代表了上一執(zhí)行單元的Span ID拧烦；Annotation代表了該Span中記錄的事件（這里主要用來記錄HTTP請求的四個(gè)階段，表中內(nèi)容作了省略處理钝计，只記錄了Annotation名稱（sr代表服務(wù)端接收請求恋博，ss代表服務(wù)端發(fā)送請求齐佳，cs代表客戶端發(fā)送請求，cr代表客戶端接收請求）债沮，省略了一些其他細(xì)節(jié)信息炼吴，比如服務(wù)名、時(shí)間戳疫衩、IP地址硅蹦、端口號等信息）；Binary Annotation代表了事件的補(bǔ)充信息（Sleuth的原始Span記錄更為詳細(xì)闷煤，Zipkin的Span處理后會去掉一些內(nèi)容童芹，對于有Annotation標(biāo)識的信息，不再使用Binary Annotation補(bǔ)充鲤拿，在上表中我們只記錄了服務(wù)名假褪、類名、方法名近顷，同樣省略了一些其他信息生音，比如：時(shí)間戳、IP地址窒升、端口號等信息）缀遍。
通過收集到的Zipkin Span詳細(xì)信息，我們很容易的可以將它們與本節(jié)開始時(shí)介紹的一次調(diào)用鏈路中的10個(gè)標(biāo)簽內(nèi)容聯(lián)系起來：
-
Span ID = T的標(biāo)簽有2個(gè)饱须，分別是序號1和10域醇，它們分別表示這次請求的開始和結(jié)束。它們對應(yīng)了上表中ID為e9a933ec50d180d6的Span冤寿，該Span的內(nèi)容在標(biāo)簽10執(zhí)行結(jié)束后歹苦，由trace-1將標(biāo)簽1和10合并成一個(gè)Span發(fā)送給Zipkin Server。 -
Span ID = A的標(biāo)簽有2個(gè)督怜，分別是序號2和9，它們分別表示了trace-1請求接收后狠角，具體處理方法調(diào)用的開始和結(jié)束号杠。該Span的內(nèi)容在標(biāo)簽9執(zhí)行結(jié)束后，由trace-1將標(biāo)簽2和9合并成一個(gè)Span發(fā)送給Zipkin Server丰歌。 -
Span ID = B的標(biāo)簽有4個(gè)姨蟋，分別是序號3、4立帖、7眼溶、8，該Span比較特殊晓勇，它的產(chǎn)生跨越了兩個(gè)實(shí)例堂飞，其中標(biāo)簽3和8是由trace-1生成的灌旧，而標(biāo)簽4和7則是由trace-2生成的，所以該標(biāo)簽會拆分成兩個(gè)Span內(nèi)容發(fā)送給Zipkin Server绰筛。trace-1會在標(biāo)簽8結(jié)束的時(shí)候?qū)?biāo)簽3和8合并成一個(gè)Span發(fā)送給Zipkin Server枢泰，而trace-2會在標(biāo)簽7結(jié)束的時(shí)候?qū)?biāo)簽4和7合并成一個(gè)Span發(fā)送給Zipkin Server。 -
Span ID = C的標(biāo)簽有2個(gè)铝噩，分別是序號5和6衡蚂，它們分別表示了trace-2請求接收后，具體處理方法調(diào)用的開始和結(jié)束骏庸。該Span的內(nèi)容在標(biāo)簽6執(zhí)行結(jié)束后毛甲，由trace-2將標(biāo)簽2和9合并成一個(gè)Span發(fā)送給Zipkin Server。
所以具被，根據(jù)上面的分析玻募，Zipkin總共會收到5個(gè)Span：一個(gè)Span T，一個(gè)Span A硬猫，兩個(gè)Span B补箍，一個(gè)Span C。結(jié)合之前請求鏈路的標(biāo)簽圖和這里的Span記錄啸蜜，我們可以總結(jié)出如下圖所示的Span收集過程坑雅，讀者可以參照此圖來理解Span收集過程的處理邏輯以及各個(gè)Span之間的關(guān)系。
雖然衬横，Zipkin服務(wù)端接收到了5個(gè)Span裹粤，但就如前文中分析的那樣，其中有兩個(gè)Span ID=B的標(biāo)簽蜂林，由于它們來自于同一個(gè)HTTP請求（trace-1對trace-2的服務(wù)調(diào)用）遥诉，概念上它們屬于同一個(gè)工作單元，因此Zipkin服務(wù)端在前端展現(xiàn)分析詳情時(shí)會將這兩個(gè)Span合并了來顯示噪叙，而合并后的Span數(shù)量就是在請求鏈路詳情頁面中Total Spans的數(shù)量矮锈。
下圖是本章示例的一個(gè)請求鏈路詳情頁面，在頁面中顯示了各個(gè)Span的延遲統(tǒng)計(jì)睁蕾，其中第三條Span信息就是trace-1對trace-2的HTTP請求調(diào)用苞笨，通過點(diǎn)擊它可以查看該Span的詳細(xì)信息，點(diǎn)擊后會以模態(tài)框的方式彈出Span詳細(xì)信息（如圖下半部分）子眶，在彈出框中詳細(xì)展示了Span的Annotation和BinaryAnnotation信息瀑凝，在Annotation區(qū)域我們可以看到它同時(shí)包含了trace-1和trace-2發(fā)送的Span信息，而在BinaryAnnotation區(qū)域則展示了該HTTP請求的詳細(xì)信息臭杰。
完整示例：
讀者可以根據(jù)喜好選擇下面的兩個(gè)倉庫中查看trace-1和trace-2兩個(gè)項(xiàng)目：
- Github：https://github.com/dyc87112/SpringCloud-Learning/
- Gitee：https://gitee.com/didispace/SpringCloud-Learning/
如果您對這些感興趣粤咪，歡迎star、follow渴杆、收藏寥枝、轉(zhuǎn)發(fā)給予支持宪塔！
本文內(nèi)容部分節(jié)選自我的《Spring Cloud微服務(wù)實(shí)戰(zhàn)》，但對依賴的Spring Boot和Spring Cloud版本做了升級脉顿。
