Sleuth鏈路跟蹤

文檔地址：https://docs.spring.io/spring-cloud-sleuth/docs/2.2.4.BUILD-SNAPSHOT/reference/html/

git地址：https://github.com/spring-cloud/spring-cloud-sleuth/

1.sleuth簡介

1. sleuth簡單介紹

　　在微服務框架中，一個由客戶端發起的請求在后端系統中會經過多個不同的服務節點調用來協同產生最后的請求結果，每一個前段請求都會形成一條復雜的分布式服務調用鏈，鏈路中的任何一環出現高延時或錯誤都會引起整個請求的失敗。

　　sleuth提供了一套完整的服務跟蹤的解決方案。包括鏈路追蹤（可以看到每個請求的依賴服務）、性能分析（可以看到在每個調用消耗的時間）以及通過鏈路分析程序錯誤等。

　　在分布式系統中提供追蹤解決方案並且兼容支持了zipkin。其實就是sleuth負責監控，zipkin負責展現。

　　官網：https://github.com/spring-cloud/spring-cloud-sleuth

　　Springcloud從F版不需要自己構建ZipkinServer，只需要下載jar包運行即可。下載地址：http://dl.bintray.com/openzipkin/maven/io/zipkin/java/zipkin-server/

2.術語介紹

Trace：一系列spans組成的一個樹狀結構，表示一條調用鏈路，一條鏈路通過Trace Id唯一標識。

Span：表示調用鏈路來源，通俗的理解span就是一次請求信息，各span通過parentid關聯起來。

Annotation：用來及時記錄一個事件的存在，一些核心annotations用來定義一個請求的開始和結束

　　cs - Client Sent -客戶端發起一個請求，這個annotion描述了這個span的開始

　　sr - Server Received -服務端獲得請求並准備開始處理它，如果將其sr減去cs時間戳便可得到網絡延遲

　　ss - Server Sent -注解表明請求處理的完成(當請求返回客戶端)，如果ss減去sr時間戳便可得到服務端需要的處理請求時間

　　cr - Client Received -表明span的結束，客戶端成功接收到服務端的回復，如果cr減去cs時間戳便可得到客戶端從服務端獲取回復的所有所需時間

2.使用sleuth開始監控

1.下載zipkin並啟動

1.下載

 zipkin-server-2.12.9-exec.jar

2.啟動zipkin

java -jar ./zipkin-server-2.12.9-exec.jar

3.訪問測試，zipkin默認端口是9411

2.修改原來的支付項目，支持鏈路追蹤

1.修改pom，增加如下依賴：

        <!-- 包含了sleuth zipkin 數據鏈路追蹤-->
        <dependency>
            <groupId>org.springframework.cloud</groupId>
            <artifactId>spring-cloud-starter-zipkin</artifactId>
        </dependency>

2.修改yml，增加zipkin和sleuth相關信息

spring:
  application:
    name: cloud-payment-service
#    sleuth鏈路追蹤
  zipkin:
    base-url: http://localhost:9411
  sleuth:
    sampler:
      #采樣取值介於 0到1之間，1則表示全部收集
      probability: 1

3.修改原來的訂單項目，支持鏈路追蹤

1.修改pom，增加如下依賴

        <!-- 包含了sleuth zipkin 數據鏈路追蹤-->
        <dependency>
            <groupId>org.springframework.cloud</groupId>
            <artifactId>spring-cloud-starter-zipkin</artifactId>
        </dependency>

2.修改yml

spring:
  application:
      name: cloud-order-service
#    sleuth鏈路追蹤
  zipkin:
    base-url: http://localhost:9411
  sleuth:
    sampler:
      #采樣取值介於 0到1之間，1則表示全部收集
      probability: 1

4.啟動后測試

 　　依次啟動eureka-》支付服務-》訂單服務，然后訪問如下：

(1)訪問訂單服務，訂單服務內部調用支付服務

http://localhost/consumer/pay/getServerPort

(2)查看zipkin

 

 (3)點擊查看請求詳情

 

 (4)點擊時間：如下

圖一：parentid為空

 

 圖二：(也驗證了通過spanid標記服務請求，parentid標記上個請求)

 

　　其實，sleuth的數據也可以進行持久化到數據庫中。這個需要的時候再研究吧。

 補充：cloud集成zipkin之后日志會自動打印traceId和spanId，格式如下：

2021-01-01 20:01:20.791  INFO [cloud-payment-service,72a132d8a6579863,d71d6d4f5e7ace1b,true] 1276 --- [nio-8081-exec-3] c.qz.cloud.controller.PaymentController  : serverPort: 8081

解釋：

application name — 應用的名稱，也就是application.properties中的spring.application.name參數配置的屬性。

traceId — 為一個請求分配的ID號，用來標識一條請求鏈路。

spanId — 表示一個基本的工作單元，一個請求可以包含多個步驟，每個步驟都擁有自己的spanId。一個請求包含一個TraceId，多個SpanId

export — 布爾類型。表示是否要將該信息輸出到類似Zipkin這樣的聚合器進行收集和展示

補充：sleuth原理簡單理解

1》traceId和spanId在服務間傳遞在調用的時候通過header傳遞的 ，官方給出的圖如下：

2》在服務內部是通過MDC傳遞的，可以理解為通過ThreadLocal傳遞，官方解釋如下：

 源碼如下：

package org.springframework.cloud.sleuth.log;

import java.util.AbstractMap;
import java.util.ArrayList;
import java.util.Collections;
import java.util.List;

import brave.internal.HexCodec;
import brave.internal.Nullable;
import brave.propagation.CurrentTraceContext;
import brave.propagation.ExtraFieldPropagation;
import brave.propagation.TraceContext;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

import org.springframework.cloud.sleuth.autoconfig.SleuthProperties;
import org.springframework.util.StringUtils;

final class Slf4jScopeDecorator implements CurrentTraceContext.ScopeDecorator {

    // Backward compatibility for all logging patterns
    private static final String LEGACY_EXPORTABLE_NAME = "X-Span-Export";

    private static final String LEGACY_PARENT_ID_NAME = "X-B3-ParentSpanId";

    private static final String LEGACY_TRACE_ID_NAME = "X-B3-TraceId";

    private static final String LEGACY_SPAN_ID_NAME = "X-B3-SpanId";

    private static final Logger log = LoggerFactory.getLogger(Slf4jScopeDecorator.class);

    private final SleuthProperties sleuthProperties;

    private final SleuthSlf4jProperties sleuthSlf4jProperties;

    Slf4jScopeDecorator(SleuthProperties sleuthProperties,
            SleuthSlf4jProperties sleuthSlf4jProperties) {
        this.sleuthProperties = sleuthProperties;
        this.sleuthSlf4jProperties = sleuthSlf4jProperties;
    }

    static void replace(String key, @Nullable String value) {
        if (value != null) {
            MDC.put(key, value);
        }
        else {
            MDC.remove(key);
        }
    }

    @Override
    public CurrentTraceContext.Scope decorateScope(TraceContext currentSpan,
            CurrentTraceContext.Scope scope) {
        final String previousTraceId = MDC.get("traceId");
        final String previousParentId = MDC.get("parentId");
        final String previousSpanId = MDC.get("spanId");
        final String spanExportable = MDC.get("spanExportable");
        final String legacyPreviousTraceId = MDC.get(LEGACY_TRACE_ID_NAME);
        final String legacyPreviousParentId = MDC.get(LEGACY_PARENT_ID_NAME);
        final String legacyPreviousSpanId = MDC.get(LEGACY_SPAN_ID_NAME);
        final String legacySpanExportable = MDC.get(LEGACY_EXPORTABLE_NAME);
        final List<AbstractMap.SimpleEntry<String, String>> previousMdc = previousMdc();

        if (currentSpan != null) {
            String traceIdString = currentSpan.traceIdString();
            MDC.put("traceId", traceIdString);
            MDC.put(LEGACY_TRACE_ID_NAME, traceIdString);
            String parentId = currentSpan.parentId() != null
                    ? HexCodec.toLowerHex(currentSpan.parentId()) : null;
            replace("parentId", parentId);
            replace(LEGACY_PARENT_ID_NAME, parentId);
            String spanId = HexCodec.toLowerHex(currentSpan.spanId());
            MDC.put("spanId", spanId);
            MDC.put(LEGACY_SPAN_ID_NAME, spanId);
            String sampled = String.valueOf(currentSpan.sampled());
            MDC.put("spanExportable", sampled);
            MDC.put(LEGACY_EXPORTABLE_NAME, sampled);
            log("Starting scope for span: {}", currentSpan);
            if (currentSpan.parentId() != null) {
                if (log.isTraceEnabled()) {
                    log.trace("With parent: {}", currentSpan.parentId());
                }
            }
            for (String key : whitelistedBaggageKeysWithValue(currentSpan)) {
                MDC.put(key, ExtraFieldPropagation.get(currentSpan, key));
            }
            for (String key : whitelistedPropagationKeysWithValue(currentSpan)) {
                MDC.put(key, ExtraFieldPropagation.get(currentSpan, key));
            }
            for (String key : whitelistedLocalKeysWithValue(currentSpan)) {
                MDC.put(key, ExtraFieldPropagation.get(currentSpan, key));
            }
        }
        else {
            MDC.remove("traceId");
            MDC.remove("parentId");
            MDC.remove("spanId");
            MDC.remove("spanExportable");
            MDC.remove(LEGACY_TRACE_ID_NAME);
            MDC.remove(LEGACY_PARENT_ID_NAME);
            MDC.remove(LEGACY_SPAN_ID_NAME);
            MDC.remove(LEGACY_EXPORTABLE_NAME);
            for (String s : whitelistedBaggageKeys()) {
                MDC.remove(s);
            }
            for (String s : whitelistedPropagationKeys()) {
                MDC.remove(s);
            }
            for (String s : whitelistedLocalKeys()) {
                MDC.remove(s);
            }
            previousMdc.clear();
        }

        /**
         * Thread context scope.
         *
         * @author Adrian Cole
         */
        class ThreadContextCurrentTraceContextScope implements CurrentTraceContext.Scope {

            @Override
            public void close() {
                log("Closing scope for span: {}", currentSpan);
                scope.close();
                replace("traceId", previousTraceId);
                replace("parentId", previousParentId);
                replace("spanId", previousSpanId);
                replace("spanExportable", spanExportable);
                replace(LEGACY_TRACE_ID_NAME, legacyPreviousTraceId);
                replace(LEGACY_PARENT_ID_NAME, legacyPreviousParentId);
                replace(LEGACY_SPAN_ID_NAME, legacyPreviousSpanId);
                replace(LEGACY_EXPORTABLE_NAME, legacySpanExportable);
                for (AbstractMap.SimpleEntry<String, String> entry : previousMdc) {
                    replace(entry.getKey(), entry.getValue());
                }
            }

        }
        return new ThreadContextCurrentTraceContextScope();
    }

    private List<AbstractMap.SimpleEntry<String, String>> previousMdc() {
        List<AbstractMap.SimpleEntry<String, String>> previousMdc = new ArrayList<>();
        List<String> keys = new ArrayList<>(whitelistedBaggageKeys());
        keys.addAll(whitelistedPropagationKeys());
        keys.addAll(whitelistedLocalKeys());
        for (String key : keys) {
            previousMdc.add(new AbstractMap.SimpleEntry<>(key, MDC.get(key)));
        }
        return previousMdc;
    }

    private List<String> whitelistedKeys(List<String> keysToFilter) {
        List<String> keys = new ArrayList<>();
        for (String baggageKey : keysToFilter) {
            if (this.sleuthSlf4jProperties.getWhitelistedMdcKeys().contains(baggageKey)) {
                keys.add(baggageKey);
            }
        }
        return keys;
    }

    private List<String> whitelistedBaggageKeys() {
        return whitelistedKeys(this.sleuthProperties.getBaggageKeys());
    }

    private List<String> whitelistedKeysWithValue(TraceContext context,
            List<String> keys) {
        if (context == null) {
            return Collections.EMPTY_LIST;
        }
        List<String> nonEmpty = new ArrayList<>();
        for (String key : keys) {
            if (StringUtils.hasText(ExtraFieldPropagation.get(context, key))) {
                nonEmpty.add(key);
            }
        }
        return nonEmpty;
    }

    private List<String> whitelistedBaggageKeysWithValue(TraceContext context) {
        return whitelistedKeysWithValue(context, whitelistedBaggageKeys());
    }

    private List<String> whitelistedPropagationKeys() {
        return whitelistedKeys(this.sleuthProperties.getPropagationKeys());
    }

    private List<String> whitelistedLocalKeys() {
        return whitelistedKeys(this.sleuthProperties.getLocalKeys());
    }

    private List<String> whitelistedPropagationKeysWithValue(TraceContext context) {
        return whitelistedKeysWithValue(context, whitelistedPropagationKeys());
    }

    private List<String> whitelistedLocalKeysWithValue(TraceContext context) {
        return whitelistedKeysWithValue(context, whitelistedLocalKeys());
    }

    private void log(String text, TraceContext span) {
        if (span == null) {
            return;
        }
        if (log.isTraceEnabled()) {
            log.trace(text, span);
        }
    }

}

(3) logback默認打出的日志會加入appname、traceId、spaceId、Export信息，官方解釋如下：

 測試：

(1)order服務日志如下：

2021-02-08 19:10:26.593 DEBUG [cloud-order-service,7521499505d655df,7521499505d655df,true] 89224 --- [nio-8088-exec-4] cn.qz.cloud.service.PaymentFeignService  : [PaymentFeignService#getServerPort] ---> GET http://CLOUD-PAYMENT-SERVICE/pay/getServerPort HTTP/1.1
2021-02-08 19:10:26.593 DEBUG [cloud-order-service,7521499505d655df,7521499505d655df,true] 89224 --- [nio-8088-exec-4] cn.qz.cloud.service.PaymentFeignService  : [PaymentFeignService#getServerPort] ---> END HTTP (0-byte body)

(2) payment日志如下：

2021-02-08 19:10:26.596  INFO [cloud-payment-service,7521499505d655df,69a517ce04d901b9,true] 47764 --- [nio-8081-exec-9] cn.qz.cloud.filter.HeaderFilter          : key: x-b3-traceid, value: 7521499505d655df
2021-02-08 19:10:26.597  INFO [cloud-payment-service,7521499505d655df,69a517ce04d901b9,true] 47764 --- [nio-8081-exec-9] cn.qz.cloud.filter.HeaderFilter          : key: x-b3-spanid, value: 69a517ce04d901b9
2021-02-08 19:10:26.597  INFO [cloud-payment-service,7521499505d655df,69a517ce04d901b9,true] 47764 --- [nio-8081-exec-9] cn.qz.cloud.filter.HeaderFilter          : key: x-b3-parentspanid, value: 7521499505d655df
2021-02-08 19:10:26.597  INFO [cloud-payment-service,7521499505d655df,69a517ce04d901b9,true] 47764 --- [nio-8081-exec-9] cn.qz.cloud.filter.HeaderFilter          : key: x-b3-sampled, value: 1
2021-02-08 19:10:26.597  INFO [cloud-payment-service,7521499505d655df,69a517ce04d901b9,true] 47764 --- [nio-8081-exec-9] cn.qz.cloud.filter.HeaderFilter          : key: accept, value: */*
2021-02-08 19:10:26.597  INFO [cloud-payment-service,7521499505d655df,69a517ce04d901b9,true] 47764 --- [nio-8081-exec-9] cn.qz.cloud.filter.HeaderFilter          : key: user-agent, value: Java/1.8.0_171
2021-02-08 19:10:26.597  INFO [cloud-payment-service,7521499505d655df,69a517ce04d901b9,true] 47764 --- [nio-8081-exec-9] cn.qz.cloud.filter.HeaderFilter          : key: host, value: 12.0.215.93:8081
2021-02-08 19:10:26.597  INFO [cloud-payment-service,7521499505d655df,69a517ce04d901b9,true] 47764 --- [nio-8081-exec-9] cn.qz.cloud.filter.HeaderFilter          : key: connection, value: keep-alive    

補充：Sleuth對其他相關的組件進行了集成

 (1) 對@Async 異步線程池做了集成，官方解釋如下：也就是說trace信息為同主線程一樣，每個@Async標注的異步方法會生成一個新的Span信息。簡單的說就是traceId同主線程一樣，spanId重新生成：