本节之前，我们已经详细介绍了如何引入Sleuth跟踪信息，搭建Zipkin服务器分析跟踪延迟。相信大家对Sleuth和Zipkin已经有了一定的感性认识。下面详细介绍Zipkin收集trace信息的过程，帮助我们更好的理解Sleuth生产trace信息和输出trace信息的整体流程和工作原理。数据模型让我们先看看Zipkin中关于跟踪信息的一些基本概念。由于Zipkin的实现借鉴了Google的Dapper，所以它们的核心术语相似，主要包括：Span：代表一个基本的工作单元。我们以HTTP请求为例。一个完整的请求过程会在客户端和服务端产生多个不同的事件状态（比如下面提到的四个核心注解标识的不同阶段）。对于同一个请求，它们属于一个工作单元，所以同一个HTTP请求流程中的四个Annotation属于一个Span。每个不同的工作单元都由一个称为SpanID的64位ID唯一标识。此外，工作单元中还存储了一个用于串联其他工作单元的ID，该工作单元也由一个64位的ID唯一标识，称为TraceID。同一个请求链路中的不同工作单元会有不同的spanID，但是它们的traceID是相同的，所以通过traceID，可以将依赖于一个请求的所有依赖请求串联起来，形成一条请求链路。除了这两个核心ID之外，Span中还存储了一些其他的信息，比如：描述信息、事件时间戳、Annotation的键值对属性、上层工作单元的SpanID等。Trace：它是由一系列具有相同TraceID的Spans串联而成的树状结构。在一个复杂的分布式系统中，每个外部请求通常都会产生一个复杂的树状结构的Trace。注释：用于及时记录一个事件的存在。我们可以将Annotation理解为包含时间戳的事件标签。对于一个HTTP请求，Sleuth中定义了以下四个核心Annotation来标识请求的开始和结束：HTTP请求。sr(ServerReceived)：这个Annotation用来记录服务器已经收到请求，准备开始处理。通过计算sr和csAnnotations的时间戳的差值，我们可以得到当前HTTP请求的网络延迟。ss（ServerSend）：该Annotation用于记录服务器在处理完请求后准备发送请求响应信息。通过计算ss和sr注解的时间戳的差值，我们可以得到当前服务器处理请求所花费的时间。cr（ClientReceived）：这个Annotation用来记录客户端从服务器收到的响应，同时也标志着HTTP请求的结束。通过计算cr和cs注解的时间戳差值，我们可以得到HTTP请求从客户端发起到收到服务器响应的总耗时。BinaryAnnotation：用于给跟踪信息添加一些额外的补充说明，通常以键值对的形式。例如：记录收到HTTP请求后执行具体业务逻辑时，没有默认的Annotation来标识事件状态，而是有BinaryAnnotation信息来补充。采集机制了解了Zipkin的基本概念之后，下面结合前面章节实现的例子，来介绍和理解SpringCloudSleuth是如何完成请求调用链路的跟踪信息的生产、输出和后续处理的。首先，我们看一下调用请求时Sleuth是如何记录和生成trace信息的。下图展示了本章我们实现的例子的全过程：客户端向trace-1发送一个HTTP请求，trace-1依赖trace-2的服务，所以trace-1再发送一个HTTP请求给trace-2，trace-2返回response后，trace-1整理response返回给client。在上图中的请求流程中，我们为整个调用流程标注了10个标签，分别代表请求链接运行过程中记录的几个重要事件的状态。我们把这些标签按照事件发生的时间顺序进行编号，从小到大编号，1代表请求开始，10代表请求结束。每个标签记录了我们上面提到的一些核心元素：TraceID、SpanID和Annotation。由于这些标签都来自同一个请求，所以它们的TraceID是相同的，标签1和标签10是起始节点和结束节点，它们的TraceID和SpanID是相同的。根据SpanID，我们可以发现在这些tag中一共生成了4个不同ID的Span，这4个Span分别代表了这样4个工作单元：SpanT：记录客户端请求到达trace-1和trace-1发送两个请求响应事件，可以计算出客户端请求响应过程的总延迟时间。SpanA：记录trace-1应用收到客户端请求后调用处理方法的开始和结束。它可以计算出使用trace-1应用程序处理客户端请求时内部逻辑所花费的时间延迟。SpanB：记录了trace-1应用程序向trace-2应用程序发送请求、trace-2应用程序收到请求、trace-2应用程序发送响应、trace-1应用程序收到响应四个事件.可以计算trace-1调用trace-2的整体依赖时间（cr-cs），也可以计算trace-1到trace-2的网络延迟（sr-cs），还可以计算内部逻辑开销trace-2应用程序处理客户端请求的时间延迟(ss-sr)。SpanC：记录trace-2应用收到trace-1请求后调用处理方法的开始和结束。它可以计算trace-2应用程序处理来自trace-1的请求的内部逻辑。耽误的时间。图中所示的四个Span与ZipkinViewTrackingDetails页面显示的内容完全对应，它们的对应关系如下图所示：server（如下图），查询结果页面显示的span是5个，点击进入trackingdetails页面时，显示的TotalSpans是4个，为什么会出现span个数不一致的情况？其实两边的跨度数是有不同含义的。查询结果页上的5个span代表接收到的Spans总数，而详情页上的TotalSpan是将接收到的Spans合并后的结果，也就是我们上一篇介绍的四个不同ID的Span内容.下面我们来详细研究下Zipkin服务器收集客户端跟踪信息的过程，看看具体收到了哪些Span内容，从而了解Zipkin中收集到的Span总数。为了更直观的观察Zipkin服务器的采集过程，我们可以通过之前实现的消息中间件的方式调试采集trace信息的程序。通过在Zipkin服务端的消息通道监听器中添加断点，我们可以清楚的知道客户端向Zipkin服务端发送了哪些信息。spring-cloud-sleuth-zipkin-stream依赖包中代码不多，我们很容易找到定义消息通道监听器的实现类：org.springframework.cloud.sleuth.zipkin.stream.ZipkinMessageListener。它的具体实现如下，其中SleuthSink.INPUT定义了监听的输入通道。默认情况下，将使用名为sleuth的主题。我们也可以通过SpringCloudStream的配置来修改。@MessageEndpoint@Conditional(NotSleuthStreamClient.class)publicclassZipkinMessageListener{finalCollectorcollector;@ServiceActivator(inputChannel=SleuthSink.INPUT)publicvoidsink(Spansinput){Listconverted=ConvertToZipkinSpanList.convert(accput.input.this);Callback.NOOP);}...}从通道监听方法的定义可以看出，Sleuth和Zipkin在集成时有两种不同的Span定义，一种是消息通道的输入对象org.springframework.cloud.sleuth.stream.Spans，这是sleuth中定义的一个Span对象，用于消息通道传输。每条消息中包含的Span信息是在org.springframework.cloud.sleuth.Span对象中定义的，但实际上在zipkinserver上使用的不是这个Span对象，而是zipkin自己的zipkin.Span对象。因此，在消息通道监听处理方法中，对sleuthSpan进行处理，每次接收到sleuthSpan，将其转化为ZipkinSpan。接下来，我们可以尝试在sink(Spansinput)方法实现的第一行代码下打断点，向trace-1发送请求，触发trace信息发送给RabbitMQ。此时通过DEBUG模式，我们可以发现消息通道收到了两个输入，一个来自trace-1，一个来自trace-2。下面两张图分别是trace-1和trace-2输出的trace信息。trace-1的trace报文中包含3个span信息，trace-2的trace报文中包含2个span信息，所以在这个request调用链上，一共发送了5个span信息，也就是我们的span个数请参阅Zipkin搜索结果页面。点击具体的Span内容，我们可以看到如下结构，其中记录了Sleuth中定义的Span的详细信息，包括Span的开始时间、结束时间、Span名称、TraceID、SpanID、Tags（对应BinaryAnnotationinZipkin）、Logs（对应Zipkin中的Annotation）等我们之前提到的核心跟踪信息。介绍到这里细心的读者可能会有这样的疑问，为什么详细信息中显示的TraceID和SpanID的值与列表中显示的摘要信息中的TraceID和SpanID的值不同？实际上TraceID和SpanID都是使用long类型存储的。在DEBUG模式下查看它的详细信息，自然是long类型，也就是它的原始值。但是，在查看Span对象时，我们看到的是通过sleuth的Span源码，对于toString()函数处理的值，我们可以看到如下定义。在输出TraceID和SpanID时，会调用idToHex函数将long类型的值转换成16进制的字符串值，所以我们在DEBUG的时候会看到两个不同的值。publicStringtoString(){return"[Trace:"+idToHex(this.traceId)+",Span:"+idToHex(this.spanId)+",Parent:"+getParentIdIfPresent()+",exportable:"+this.exportable+"]";}publicstaticStringidToHex(longid){returnLong.toHexString(id);}接收到Sleuth后，继续执行程序，可以看到转换后的ZipkinSpan内容，存储在一个名为converted的列表中，具体内容如下：上图展示了转换后的ZipkinSpan对象的详细内容。我们可以看到很多熟悉的名字，这些都是我们之前介绍过的zipkin中的基本概念，而这些基本概念对sleuth的价值也可以在sleuth的原始span中找到，其中annotations和binaryAnnotations有一些特别之处。sleuth定义的span并没有使用相同的名字，而是使用logs和tags来命名。从这里的详细信息我们可以直观的看出annotations和binaryAnnotations的作用，其中annotations存放的是当前Span包含的各种事件状态以及对应事件状态的时间戳，而binaryAnnotations存放的是events的补充信息，比如what上图中存储的是HTTP请求的详细描述信息。此外，它还可以存储调用函数的详细描述（如下图所示）。让我们仔细看看调试消息监听器接收到的五个Span内容。首先，我们可以发现每个Span都包含3个ID信息。除了标识Span本身的ID和用来标识整个链路的traceId之外，还有一个之前没有提到的parentId。它用来标识每个Span的父子关系的ID（它的值来自于上一步中执行单元Span的ID），通过parentId的定义，我们可以为每个Span找到它的前驱节点，从而定位到每个Span在请求调用链中的准确位置。每条调用链中都有一个特殊的Span，其parentId为null。我们称这种Span为RootSpan，它是这个请求调用链的根节点。为了理清这些span之间的关系，我们可以从rootspan开始梳理整个链接的span内容。下表是我们从RootSpan开始，根据每个Span的父子关系***整理出来的结果：上表中的Host代表发送Span的application；SpanID是当前Span的唯一标识；ParentSpanID表示上一个执行单元的SpanID；Annotation表示Span中记录的事件（这里主要用来记录HTTP请求的四个阶段，表中内容省略，只提供Annotation名称（sr代表服务器接收请求，ss代表服务端发送请求的，cs代表客户端发送请求，cr代表客户端接收请求），省略一些其他细节，如服务名称、时间戳、IP地址、端口号等）；BinaryAnnotation代表事件的补充信息（Sleuth的原始Span记录更详细，Zipkin的Span经过处理后会去掉一些内容。对于标注了Annotation的信息，不再使用BinaryAnnotation来补充。在上表中，我们只record省略了服务名、类名、方法名，还省略了一些其他信息，如：时间戳、IP地址、端口号等）。通过收集到的ZipkinSpan详情，我们可以很容易地将它们与本节开头介绍的一个调用链接中的10个标签的内容联系起来：有2个SpanID=T的标签，分别是序号1和10，分别是分别代表本次请求的开始和结束。它们对应于上表中ID为e9a933ec50d180d6的Span。标签10执行后，trace-1将标签1和标签10合并成一个Span发送给ZipkinServer。有两个SpanID=A的tag，分别是序号2和9，分别表示收到trace-1请求后具体处理方法调用的开始和结束。标签9执行完Span的内容后，trace-1将标签2和9组合成一个Span发送给ZipkinServer。有4个SpanID=B的tag，分别是序号3、4、7、8，这个Span比较特殊，它的生成跨越了两个instance。其中标签3和8是trace-1生成的，标签4和7是trace-2生成的，所以标签会被拆分成两个Span内容发送给ZipkinServer。trace-1会将tag3和8合并成一个Span，在tag8的末尾发送给ZipkinServer，trace-2会将tag4和7合并成一个Span，在tag7的末尾发送给ZipkinServer.有2个SpanID=C的标签，分别是序号5和6，分别表示收到trace-2请求后具体处理方法调用的开始和结束。Span的内容在标签6执行完后，trace-2将标签2和9组合成一个Span发送给ZipkinServer。因此，根据上面的分析，Zipkin一共会收到5个Span：1个SpanT，1个SpanA，2个SpanB，1个SpanC。结合前面请求链接的标签图和这里的span记录，我们可以总结如下图所示的span收集过程。读者可以参考这张图来了解span收集过程的处理逻辑以及span之间的关系。Zipkin服务端虽然收到了5个Span，但是在上一篇文章中分析过，有两个SpanID=B的标签，因为它们来自同一个HTTP请求（trace-1服务调用trace-2），概念上属于同一个workunit，所以Zipkinserver在前端展示分析详情的时候会合并这两个Spans来展示，合并后的Spans个数就是请求链接详情页中的TotalSpans个数。下图是本章示例的一个请求链接详情页面。页面显示了每个Span的延迟统计信息。第三个Span信息是trace-1到trace-2的HTTP请求调用。点击查看Span点击后会以模态框的形式弹出Span的详细信息（下图），弹窗中详细展示了Span的Annotation和BinaryAnnotation信息上框。在Annotation区域，我们可以看到还包含trace-1和trace-2发送的Span信息，BinaryAnnotation区域显示了HTTP请求的详细信息。完整示例：读者可以根据自己的喜好选择以下两个仓库查看trace-1和trace-2项目：Github：https://github.com/dyc87112/SpringCloud-Learning/Gitee：https://gitee。com/didispace/SpringCloud-Learning/【本文为专栏作者“翟永超”原创稿件，转载请联系作者获得授权】点此查看该作者更多好文
