发布于 由admin

Sleuth 链路追踪：自定义 span 与 MDC 日志

好的，没问题。咱们这就来聊聊Sleuth链路追踪，以及如何自定义Span和利用MDC（Mapped Diagnostic Context）日志，让你的微服务架构透明得像水晶一样。

Sleuth链路追踪：让微服务不再“隐身”

想象一下，你是一个侦探，要调查一个复杂的案件。线索散落在城市的各个角落，你需要追踪每一个细节，才能拼凑出真相。在微服务架构中，你的服务就是这些散落的线索，而Sleuth就是你的侦探工具。

Sleuth是一个Spring Cloud提供的链路追踪组件，它能帮助你监控和诊断微服务之间的调用关系，让你清晰地看到请求是如何在各个服务之间流动的。这对于排查性能问题、定位错误非常有帮助。

为什么需要自定义Span？

Sleuth默认会追踪Spring管理的组件，比如Controller、RestTemplate等。但有时，你可能需要在代码中添加自定义的追踪点，以便更精确地监控某些关键业务逻辑的执行情况。这时候，就需要自定义Span了。

举个例子，假设你有一个电商服务，用户下单时需要经过以下步骤：

  1. 验证用户身份
  2. 检查库存
  3. 生成订单
  4. 扣减库存
  5. 发送消息

如果你想知道哪个步骤耗时最长，或者哪个步骤出现了错误，就需要为这些步骤添加自定义的Span。

如何自定义Span？

自定义Span非常简单，只需要使用Tracer接口即可。Tracer是Sleuth的核心接口，它提供了创建和管理Span的方法。

首先，在你的Spring Boot项目中引入Sleuth依赖：

<dependency>
    <groupId>org.springframework.cloud</groupId>
    <artifactId>spring-cloud-starter-sleuth</artifactId>
</dependency>

然后，在你的代码中注入Tracer：

import org.springframework.cloud.sleuth.Tracer;
import org.springframework.stereotype.Service;

@Service
public class OrderService {

    private final Tracer tracer;

    public OrderService(Tracer tracer) {
        this.tracer = tracer;
    }

    public void createOrder(String userId, String productId, int quantity) {
        // 1. 验证用户身份
        tracer.startScopedSpan("validateUser");
        validateUser(userId);
        tracer.endScopedSpan();

        // 2. 检查库存
        tracer.startScopedSpan("checkInventory");
        checkInventory(productId, quantity);
        tracer.endScopedSpan();

        // 3. 生成订单
        tracer.startScopedSpan("generateOrder");
        generateOrder(userId, productId, quantity);
        tracer.endScopedSpan();

        // 4. 扣减库存
        tracer.startScopedSpan("deductInventory");
        deductInventory(productId, quantity);
        tracer.endScopedSpan();

        // 5. 发送消息
        tracer.startScopedSpan("sendMessage");
        sendMessage(userId, productId, quantity);
        tracer.endScopedSpan();
    }

    private void validateUser(String userId) {
        // 模拟验证用户身份
        try {
            Thread.sleep(100);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }

    private void checkInventory(String productId, int quantity) {
        // 模拟检查库存
        try {
            Thread.sleep(200);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }

    private void generateOrder(String userId, String productId, int quantity) {
        // 模拟生成订单
        try {
            Thread.sleep(150);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }

    private void deductInventory(String productId) {
        // 模拟扣减库存
        try {
            Thread.sleep(100);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }

    private void sendMessage(String userId, String productId, int quantity) {
        // 模拟发送消息
        try {
            Thread.sleep(50);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}

在上面的代码中，我们使用了tracer.startScopedSpan("spanName")来创建一个Span，并使用tracer.endScopedSpan()来结束Span。startScopedSpan 会自动创建并激活 Span， endScopedSpan 会自动结束当前激活的 Span。

Span的命名

Span的命名非常重要，好的命名能让你更容易理解Span的含义。一般来说，Span的命名应该能够清晰地描述Span所代表的业务逻辑。

Span的标签（Tags）

除了Span的名称，你还可以为Span添加标签。标签可以用来存储Span的额外信息，比如请求参数、返回值、错误信息等。

你可以使用tracer.currentSpan().tag(key, value)来添加标签：

import org.springframework.cloud.sleuth.Tracer;
import org.springframework.stereotype.Service;

@Service
public class OrderService {

    private final Tracer tracer;

    public OrderService(Tracer tracer) {
        this.tracer = tracer;
    }

    public void createOrder(String userId, String productId, int quantity) {
        tracer.startScopedSpan("validateUser");
        tracer.currentSpan().tag("user.id", userId);
        validateUser(userId);
        tracer.endScopedSpan();

        // ...
    }

    private void validateUser(String userId) {
        // 模拟验证用户身份
        try {
            Thread.sleep(100);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}

在上面的代码中，我们为validateUser这个Span添加了一个标签user.id，它的值为userId。

Span的事件（Events）

除了标签，你还可以为Span添加事件。事件可以用来记录Span的生命周期中的重要时刻，比如开始时间、结束时间、错误时间等。

你可以使用tracer.currentSpan().event(eventName)来添加事件：

import org.springframework.cloud.sleuth.Tracer;
import org.springframework.stereotype.Service;

@Service
public class OrderService {

    private final Tracer tracer;

    public OrderService(Tracer tracer) {
        this.tracer = tracer;
    }

    public void createOrder(String userId, String productId, int quantity) {
        tracer.startScopedSpan("validateUser");
        tracer.currentSpan().event("start");
        validateUser(userId);
        tracer.currentSpan().event("end");
        tracer.endScopedSpan();

        // ...
    }

    private void validateUser(String userId) {
        // 模拟验证用户身份
        try {
            Thread.sleep(100);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}

在上面的代码中，我们为validateUser这个Span添加了两个事件：start和end。

MDC（Mapped Diagnostic Context）：让日志携带追踪信息

有了Span，我们就可以追踪请求在各个服务之间的调用关系了。但是，如果服务内部出现了错误，我们如何将错误信息与对应的Span关联起来呢？这时候，就需要MDC了。

MDC是logback和log4j等日志框架提供的一种机制，它允许你在日志中添加一些上下文信息，比如用户ID、请求ID、追踪ID等。Sleuth会自动将追踪ID（traceId）和Span ID（spanId）添加到MDC中。

如何使用MDC？

要使用MDC，你需要在你的logback.xml或log4j.xml配置文件中添加以下配置：

logback.xml:

<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - [%X{traceId},%X{spanId}] - %msg%n</pattern>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

log4j.xml:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">

    <appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - [%X{traceId},%X{spanId}] - %m%n" />
        </layout>
    </appender>

    <root>
        <level value="INFO" />
        <appender-ref ref="CONSOLE" />
    </root>
</log4j:configuration>

在上面的配置中，我们使用了%X{traceId}和%X{spanId}来获取追踪ID和Span ID。

然后，在你的代码中，你就可以像这样使用MDC：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.cloud.sleuth.Tracer;
import org.springframework.stereotype.Service;

@Service
public class OrderService {

    private static final Logger logger = LoggerFactory.getLogger(OrderService.class);

    private final Tracer tracer;

    public OrderService(Tracer tracer) {
        this.tracer = tracer;
    }

    public void createOrder(String userId, String productId, int quantity) {
        try {
            tracer.startScopedSpan("validateUser");
            validateUser(userId);
            tracer.endScopedSpan();

            // ...
        } catch (Exception e) {
            logger.error("Failed to create order", e);
            throw e;
        }
    }

    private void validateUser(String userId) {
        // 模拟验证用户身份
        try {
            Thread.sleep(100);
        } catch (InterruptedException e) {
            logger.error("Validate User Failed", e);
            e.printStackTrace();
        }
    }
}

在上面的代码中，当validateUser方法抛出异常时，我们会使用logger.error方法记录错误信息。由于我们配置了MDC，所以错误日志会自动携带追踪ID和Span ID。

Sleuth + 自定义Span + MDC：完美组合

Sleuth、自定义Span和MDC结合起来，可以让你对微服务架构的运行情况了如指掌。你可以使用Sleuth追踪请求在各个服务之间的调用关系，使用自定义Span监控关键业务逻辑的执行情况，使用MDC将错误信息与对应的Span关联起来。

一些最佳实践

  • Span的命名要清晰、简洁。
  • 为Span添加必要的标签，方便后续分析。
  • 使用MDC将错误信息与对应的Span关联起来。
  • 定期检查你的Sleuth配置，确保其正常工作。
  • 结合Zipkin或其他链路追踪工具，可视化你的追踪数据。

示例代码：一个完整的例子

假设我们有两个微服务：order-service和inventory-service。order-service负责处理订单，inventory-service负责管理库存。

order-service:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.cloud.sleuth.Tracer;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.PathVariable;
import org.springframework.web.bind.annotation.RestController;
import org.springframework.web.client.RestTemplate;

@RestController
public class OrderController {

    private static final Logger logger = LoggerFactory.getLogger(OrderController.class);

    @Autowired
    private Tracer tracer;

    @Autowired
    private RestTemplate restTemplate;

    @GetMapping("/orders/{orderId}")
    public String getOrder(@PathVariable String orderId) {
        tracer.startScopedSpan("getOrder");
        logger.info("Received request for order ID: {}", orderId);
        String inventoryResponse = restTemplate.getForObject("http://inventory-service/inventory/" + orderId, String.class);
        logger.info("Received inventory response: {}", inventoryResponse);
        tracer.endScopedSpan();
        return "Order details: " + orderId + ", Inventory: " + inventoryResponse;
    }
}

inventory-service:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.cloud.sleuth.Tracer;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.PathVariable;
import org.springframework.web.bind.annotation.RestController;

@RestController
public class InventoryController {

    private static final Logger logger = LoggerFactory.getLogger(InventoryController.class);

    private final Tracer tracer;

    public InventoryController(Tracer tracer) {
        this.tracer = tracer;
    }

    @GetMapping("/inventory/{productId}")
    public String getInventory(@PathVariable String productId) {
        tracer.startScopedSpan("getInventory");
        logger.info("Received request for product ID: {}", productId);
        try {
            Thread.sleep(200); // Simulate some processing time
        } catch (InterruptedException e) {
            logger.error("Interrupted!", e);
            Thread.currentThread().interrupt();
        }
        tracer.endScopedSpan();
        return "Inventory for product ID: " + productId + " is available.";
    }
}

在这个例子中，order-service会调用inventory-service来获取库存信息。Sleuth会自动追踪这两个服务之间的调用关系。我们还在每个方法的开头和结尾添加了自定义的Span，以便更精确地监控方法的执行情况。同时，我们使用了MDC，所以日志会自动携带追踪ID和Span ID。

表格总结：Sleuth、自定义Span和MDC的用途

功能 描述
Sleuth 提供链路追踪功能，自动追踪Spring管理的组件之间的调用关系。
自定义Span 允许你在代码中添加自定义的追踪点，以便更精确地监控某些关键业务逻辑的执行情况。
MDC 允许你在日志中添加上下文信息，比如追踪ID和Span ID，以便将错误信息与对应的Span关联起来。

调试和问题排查

  • 检查依赖： 确保你的项目中包含了正确的Sleuth依赖。
  • 检查配置： 确保你的application.properties或application.yml文件中包含了正确的Sleuth配置。
  • 检查日志： 检查你的日志，看看是否有错误信息。
  • 使用Zipkin或其他链路追踪工具： 使用Zipkin或其他链路追踪工具，可视化你的追踪数据，可以帮助你更容易地发现问题。

总结

Sleuth链路追踪、自定义Span和MDC是微服务架构中不可或缺的工具。它们可以帮助你监控和诊断微服务之间的调用关系，让你清晰地看到请求是如何在各个服务之间流动的。通过合理地使用这些工具，你可以让你的微服务架构透明得像水晶一样，从而更容易地排查性能问题、定位错误。希望这篇文章能帮助你更好地理解和使用这些工具，让你的微服务架构更加健壮和可靠。 祝你编码愉快！

发表回复

您的邮箱地址不会被公开。 必填项已用 * 标注