如何引入Sleuth跟蹤信息和搭建Zipkin服務(wù)端分析跟蹤延遲的過(guò)程做了詳細的介紹，相信大家對于Sleuth和Zipkin已經(jīng)有了一定的感性認識。接下來(lái)，我們介紹一下關(guān)于Zipkin收集跟蹤信息的過(guò)程細節，以幫助我們更好地理解Sleuth生產(chǎn)跟蹤信息以及輸出跟蹤信息的整體過(guò)程和工作原理。

數據模型

我們先來(lái)看看Zipkin中關(guān)于跟蹤信息的一些基礎概念。由于Zipkin的實(shí)現借鑒了Google的Dapper，所以它們有著(zhù)類(lèi)似的核心術(shù)語(yǔ)，主要有下面幾個(gè)內容：

Span：它代表了一個(gè)基礎的工作單元。我們以HTTP請求為例，一次完整的請求過(guò)程在客戶(hù)端和服務(wù)端都會(huì )產(chǎn)生多個(gè)不同的事件狀態(tài)（比如下面所說(shuō)的四個(gè)核心Annotation所標識的不同階段），對于同一個(gè)請求來(lái)說(shuō)，它們屬于一個(gè)工作單元，所以同一HTTP請求過(guò)程中的四個(gè)Annotation同屬于一個(gè)Span。每一個(gè)不同的工作單元都通過(guò)一個(gè)64位的ID來(lái)唯一標識，稱(chēng)為Span ID。另外，在工作單元中還存儲了一個(gè)用來(lái)串聯(lián)其他工作單元的ID，它也通過(guò)一個(gè)64位的ID來(lái)唯一標識，稱(chēng)為T(mén)race ID。在同一條請求鏈路中的不同工作單元都會(huì )有不同的Span ID，但是它們的Trace ID是相同的，所以通過(guò)Trace ID可以將一次請求中依賴(lài)的所有依賴(lài)請求串聯(lián)起來(lái)形成請求鏈路。除了這兩個(gè)核心的ID之外，Span中還存儲了一些其他信息，比如：描述信息、事件時(shí)間戳、Annotation的鍵值對屬性、上一級工作單元的Span ID等。Trace：它是由一系列具有相同Trace ID的Span串聯(lián)形成的一個(gè)樹(shù)狀結構。在復雜的分布式系統中，每一個(gè)外部請求通常都會(huì )產(chǎn)生一個(gè)復雜的樹(shù)狀結構的Trace。Annotation：它用來(lái)及時(shí)地記錄一個(gè)事件的存在。我們可以把Annotation理解為一個(gè)包含有時(shí)間戳的事件標簽，對于一個(gè)HTTP請求來(lái)說(shuō)，在Sleuth中定義了下面四個(gè)核心Annotation來(lái)標識一個(gè)請求的開(kāi)始和結束：cs（Client Send）：該Annotation用來(lái)記錄客戶(hù)端發(fā)起了一個(gè)請求，同時(shí)它也標識了這個(gè)HTTP請求的開(kāi)始。sr（Server Received）：該Annotation用來(lái)記錄服務(wù)端接收到了請求，并準備開(kāi)始處理它。通過(guò)計算sr與cs兩個(gè)Annotation的時(shí)間戳之差，我們可以得到當前HTTP請求的網(wǎng)絡(luò )延遲。ss（Server Send）：該Annotation用來(lái)記錄服務(wù)端處理完請求后準備發(fā)送請求響應信息。通過(guò)計算ss與sr兩個(gè)Annotation的時(shí)間戳之差，我們可以得到當前服務(wù)端處理請求的時(shí)間消耗。cr（Client Received）：該Annotation用來(lái)記錄客戶(hù)端接收到服務(wù)端的回復，同時(shí)它也標識了這個(gè)HTTP請求的結束。通過(guò)計算cr與cs兩個(gè)Annotation的時(shí)間戳之差，我們可以得到該HTTP請求從客戶(hù)端發(fā)起開(kāi)始到接收服務(wù)端響應的總時(shí)間消耗。BinaryAnnotation：它用來(lái)對跟蹤信息添加一些額外的補充說(shuō)明，一般以鍵值對方式出現。比如：在記錄HTTP請求接收后執行具體業(yè)務(wù)邏輯時(shí)，此時(shí)并沒(méi)有默認的Annotation來(lái)標識該事件狀態(tài)，但是有BinaryAnnotation信息對其進(jìn)行補充。

收集機制

在理解了Zipkin的各個(gè)基本概念之后，下面我們結合前面章節中實(shí)現的例子來(lái)詳細介紹和理解Spring Cloud Sleuth是如何對請求調用鏈路完成跟蹤信息的生產(chǎn)、輸出和后續處理的。

首先，我們來(lái)看看Sleuth在請求調用時(shí)是怎么樣來(lái)記錄和生成跟蹤信息的。下圖展示了我們在本章節中實(shí)現示例的運行全過(guò)程：客戶(hù)端發(fā)送了一個(gè)HTTP請求到trace-1，trace-1依賴(lài)于trace-2的服務(wù)，所以trace-1再發(fā)送一個(gè)HTTP請求到trace-2，待trace-2返回響應之后，trace-1再組織響應結果返回給客戶(hù)端。

在上圖的請求過(guò)程中，我們?yōu)檎麄�(gè)調用過(guò)程標記了10個(gè)標簽，它們分別代表了該請求鏈路運行過(guò)程中記錄的幾個(gè)重要事件狀態(tài)，我們根據事件發(fā)生的時(shí)間順序我們?yōu)檫@些標簽做了從小到大的編號，1代表請求的開(kāi)始、10代表請求的結束。每個(gè)標簽中記錄了一些我們上面提到過(guò)的核心元素：Trace ID、Span ID以及Annotation。由于這些標簽都源自一個(gè)請求，所以他們的Trace ID相同，而標簽1和標簽10是起始和結束節點(diǎn)，它們的Trace ID與Span ID是相同的。

根據Span ID，我們可以發(fā)現在這些標簽中一共產(chǎn)生了4個(gè)不同ID的Span，這4個(gè)Span分別代表了這樣4個(gè)工作單元：

Span T：記錄了客戶(hù)端請求到達trace-1和trace-1發(fā)送請求響應的兩個(gè)事件，它可以計算出了客戶(hù)端請求響應過(guò)程的總延遲時(shí)間。Span A：記錄了trace-1應用在接收到客戶(hù)端請求之后調用處理方法的開(kāi)始和結束兩個(gè)事件，它可以計算出trace-1應用用于處理客戶(hù)端請求時(shí)，內部邏輯花費的時(shí)間延遲。Span B：記錄了trace-1應用發(fā)送請求給trace-2應用、trace-2應用接收請求，trace-2應用發(fā)送響應、trace-1應用接收響應四個(gè)事件，它可以計算出trace-1調用trace-2的總體依賴(lài)時(shí)間（cr - cs），也可以計算出trace-1到trace-2的網(wǎng)絡(luò )延遲（sr - cs），也可以計算出trace-2應用用于處理客戶(hù)端請求的內部邏輯花費的時(shí)間延遲（ss - sr）。Span C：記錄了trace-2應用在接收到trace-1的請求之后調用處理方法的開(kāi)始和結束兩個(gè)事件，它可以計算出trace-2應用用于處理來(lái)自trace-1的請求時(shí)，內部邏輯花費的時(shí)間延遲。

在圖中展現的這個(gè)4個(gè)Span正好對應了Zipkin查看跟蹤詳細頁(yè)面中的顯示內容，它們的對應關(guān)系如下圖所示：

仔細的讀者可能還有這樣一個(gè)疑惑：我們在Zipkin服務(wù)端查詢(xún)跟蹤信息時(shí)（如下圖所示），在查詢(xún)結果頁(yè)面中顯示的spans是5，而點(diǎn)擊進(jìn)入跟蹤明細頁(yè)面時(shí)，顯示的Total Spans又是4，為什么會(huì )出現span數量不一致的情況呢？

實(shí)際上這兩邊的span數量?jì)热萦胁煌�的含義，在查詢(xún)結果頁(yè)面中的5 spans代表了總共接收的Span數量，而在詳細頁(yè)面中的Total Span則是對接收Span進(jìn)行合并后的結果，也就是前文中我們介紹的4個(gè)不同ID的Span內容。下面我們來(lái)詳細研究一下Zipkin服務(wù)端收集客戶(hù)端跟蹤信息的過(guò)程，看看它到底收到了哪些具體的Span內容，從而來(lái)理解Zipkin中收集到的Span總數量。

為了更直觀(guān)的觀(guān)察Zipkin服務(wù)端的收集過(guò)程，我們可以對之前實(shí)現的消息中間件方式收集跟蹤信息的程序進(jìn)行調試。通過(guò)在Zipkin服務(wù)端的消息通道監聽(tīng)程序中增加斷點(diǎn)，我們就能清楚的知道客戶(hù)端都發(fā)送了一些什么信息到Zipkin的服務(wù)端。在spring-cloud-sleuth-zipkin-stream依賴(lài)包中的代碼并不多，我們很容易的就能找到定義消息通道監聽(tīng)的實(shí)現類(lèi)：org.springframework.cloud.sleuth.zipkin.stream.ZipkinMessageListener。它的具體實(shí)現如下所示，其中SleuthSink.INPUT定義了監聽(tīng)的輸入通道，默認會(huì )使用名為sleuth的主題，我們也可以通過(guò)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);     }     ... } 

從通道監聽(tīng)方法的定義中我們可以看到Sleuth與Zipkin在整合的時(shí)候是有兩個(gè)不同的Span定義的，一個(gè)是消息通道的輸入對象org.springframework.cloud.sleuth.stream.Spans，它是sleuth中定義的用于消息通道傳輸的Span對象，每個(gè)消息中包含的Span信息定義在org.springframework.cloud.sleuth.Span對象中，但是真正在zipkin服務(wù)端使用的并非這個(gè)Span對象，而是zipkin自己的zipkin.Span對象。所以，在消息通道監聽(tīng)處理方法中，對sleuth的Span做了處理，每次接收到sleuth的Span之后就將其轉換成Zipkin的Span。

下面我們可以嘗試在sink(Spans input)方法實(shí)現的第一行代碼中加入斷點(diǎn)，并向trace-1發(fā)送一個(gè)請求，觸發(fā)跟蹤信息發(fā)送到RabbitMQ上。此時(shí)我們通過(guò)DEBUG模式可以發(fā)現消息通道中都接收到了兩次輸入，一次來(lái)自trace-1，一次來(lái)自trace-2。下面兩張圖分別展示了來(lái)自trace-1和trace-2輸出的跟蹤消息，其中trace-1的跟蹤消息包含了3條span信息，trace-2的跟蹤消息包含了2條span信息，所以在這個(gè)請求調用鏈上，一共發(fā)送了5個(gè)span信息，也就是我們在Zipkin搜索結果頁(yè)面中看到的spans數量信息。

點(diǎn)開(kāi)一個(gè)具體的Span內容，我們可以看到如下所示的結構，它記錄了Sleuth中定義的Span詳細信息，包括該Span的開(kāi)始時(shí)間、結束時(shí)間、Span的名稱(chēng)、Trace ID、Span ID、Tags（對應Zipkin中的BinaryAnnotation）、Logs（對應Zipkin中的Annotation）等我們之前提到過(guò)的核心跟蹤信息。

介紹到這里仔細的讀者可能會(huì )有一個(gè)這樣的疑惑，在明細信息中展示的Trace ID和Span ID的值為什么與列表展示的概要信息中的Trace ID和Span ID的值不一樣呢？實(shí)際上，Trace ID和Span ID都是使用long類(lèi)型存儲的，在DEBUG模式下查看其明細時(shí)自然是long類(lèi)型，也就是它的原始值，但是在查看Span對象的時(shí)候，我們看到的是通過(guò)toString()函數處理過(guò)的值，從sleuth的Span源碼中我們可以看到如下定義，在輸出Trace ID和Span ID時(shí)都調用了idToHex函數將long類(lèi)型的值轉換成了16進(jìn)制的字符串值，所以在DEBUG時(shí)我們會(huì )看到兩個(gè)不一樣的值。

public String toString() { return"[Trace: " + idToHex(this.traceId) + ", Span: " + idToHex(this.spanId)             + ", Parent: " + getParentIdIfPresent() + ", exportable:" + this.exportable + "]"; } publicstatic String idToHex(long id) { return Long.toHexString(id); } 

在接收到Sleuth之后我們將程序繼續執行下去，可以看到經(jīng)過(guò)轉換后的Zipkin的Span內容，它們保存在一個(gè)名為converted的列表中，具體內容如下所示：

上圖展示了轉換后的Zipkin Span對象的詳細內容，我們可以看到很多熟悉的名稱(chēng)，也就是之前我們介紹的關(guān)于zipkin中的各個(gè)基本概念，而這些基本概念的值我們也都可以在之前sleuth的原始span中找到，其中annotations和binaryAnnotations有一些特殊，在sleuth定義的span中沒(méi)有使用相同的名稱(chēng)，而是使用了logs和tags來(lái)命名。從這里的詳細信息中，我們可以直觀(guān)的看到annotations和binaryAnnotations的作用，其中annotations中存儲了當前Span包含的各種事件狀態(tài)以及對應事件狀態(tài)的時(shí)間戳，而binaryAnnotations則存儲了對事件的補充信息，比如上圖中存儲的就是該HTTP請求的細節描述信息，除此之外，它也可以存儲對調用函數的詳細描述（如下圖所示）。

下面我們再來(lái)詳細看看通過(guò)調試消息監聽(tīng)程序接收到的這5個(gè)Span內容。首先，我們可以發(fā)現每個(gè)Span中都包含有3個(gè)ID信息，其中除了標識Span自身的ID以及用來(lái)標識整條鏈路的traceId之外，還有一個(gè)之前沒(méi)有提過(guò)的parentId，它是用來(lái)標識各Span父子關(guān)系的ID（它的值來(lái)自與上一步執行單元Span的ID） ，通過(guò)parentId的定義我們可以為每個(gè)Span找到它的前置節點(diǎn)，從而定位每個(gè)Span在請求調用鏈中的確切位置。在每條調用鏈路中都有一個(gè)特殊的Span，它的parentId為null，這類(lèi)Span我們稱(chēng)它為Root Span，也就是這條請求調用鏈的根節點(diǎn)。為了弄清楚這些Span之間的關(guān)系，我們可以從Root Span開(kāi)始來(lái)整理出整條鏈路的Span內容。下表展示了我們從Root Span開(kāi)始，根據各個(gè)Span的父子關(guān)系最后整理出的結果：

上表中的Host代表了該Span是從哪個(gè)應用發(fā)送過(guò)來(lái)的；Span ID是當前Span的唯一標識；Parent Span ID代表了上一執行單元的Span ID；Annotation代表了該Span中記錄的事件（這里主要用來(lái)記錄HTTP請求的四個(gè)階段，表中內容作了省略處理，只記錄了Annotation名稱(chēng)（sr代表服務(wù)端接收請求，ss代表服務(wù)端發(fā)送請求，cs代表客戶(hù)端發(fā)送請求，cr代表客戶(hù)端接收請求），省略了一些其他細節信息，比如服務(wù)名、時(shí)間戳、IP地址、端口號等信息）；Binary Annotation代表了事件的補充信息（Sleuth的原始Span記錄更為詳細，Zipkin的Span處理后會(huì )去掉一些內容，對于有Annotation標識的信息，不再使用Binary Annotation補充，在上表中我們只記錄了服務(wù)名、類(lèi)名、方法名，同樣省略了一些其他信息，比如：時(shí)間戳、IP地址、端口號等信息）。

通過(guò)收集到的Zipkin Span詳細信息，我們很容易的可以將它們與本節開(kāi)始時(shí)介紹的一次調用鏈路中的10個(gè)標簽內容聯(lián)系起來(lái)：

Span ID = T的標簽有2個(gè)，分別是序號1和10，它們分別表示這次請求的開(kāi)始和結束。它們對應了上表中ID為e9a933ec50d180d6的Span，該Span的內容在標簽10執行結束后，由trace-1將標簽1和10合并成一個(gè)Span發(fā)送給Zipkin Server。Span ID = A的標簽有2個(gè)，分別是序號2和9，它們分別表示了trace-1請求接收后，具體處理方法調用的開(kāi)始和結束。該Span的內容在標簽9執行結束后，由trace-1將標簽2和9合并成一個(gè)Span發(fā)送給Zipkin Server。Span ID = B的標簽有4個(gè)，分別是序號3、4、7、8，該Span比較特殊，它的產(chǎn)生跨越了兩個(gè)實(shí)例，其中標簽3和8是由trace-1生成的，而標簽4和7則是由trace-2生成的，所以該標簽會(huì )拆分成兩個(gè)Span內容發(fā)送給Zipkin Server。trace-1會(huì )在標簽8結束的時(shí)候將標簽3和8合并成一個(gè)Span發(fā)送給Zipkin Server，而trace-2會(huì )在標簽7結束的時(shí)候將標簽4和7合并成一個(gè)Span發(fā)送給Zipkin Server。Span ID = C的標簽有2個(gè)，分別是序號5和6，它們分別表示了trace-2請求接收后，具體處理方法調用的開(kāi)始和結束。該Span的內容在標簽6執行結束后，由trace-2將標簽2和9合并成一個(gè)Span發(fā)送給Zipkin Server。

所以，根據上面的分析，Zipkin總共會(huì )收到5個(gè)Span：一個(gè)Span T，一個(gè)Span A，兩個(gè)Span B，一個(gè)Span C。結合之前請求鏈路的標簽圖和這里的Span記錄，我們可以總結出如下圖所示的Span收集過(guò)程，讀者可以參照此圖來(lái)理解Span收集過(guò)程的處理邏輯以及各個(gè)Span之間的關(guān)系。

雖然，Zipkin服務(wù)端接收到了5個(gè)Span，但就如前文中分析的那樣，其中有兩個(gè)Span ID=B的標簽，由于它們來(lái)自于同一個(gè)HTTP請求（trace-1對trace-2的服務(wù)調用），概念上它們屬于同一個(gè)工作單元，因此Zipkin服務(wù)端在前端展現分析詳情時(shí)會(huì )將這兩個(gè)Span合并了來(lái)顯示，而合并后的Span數量就是在請求鏈路詳情頁(yè)面中Total Spans的數量。

下圖是本章示例的一個(gè)請求鏈路詳情頁(yè)面，在頁(yè)面中顯示了各個(gè)Span的延遲統計，其中第三條Span信息就是trace-1對trace-2的HTTP請求調用，通過(guò)點(diǎn)擊它可以查看該Span的詳細信息，點(diǎn)擊后會(huì )以模態(tài)框的方式彈出Span詳細信息（如圖下半部分），在彈出框中詳細展示了Span的Annotation和BinaryAnnotation信息，在A(yíng)nnotation區域我們可以看到它同時(shí)包含了trace-1和trace-2發(fā)送的Span信息，而在BinaryAnnotation區域則展示了該HTTP請求的詳細信息。