侦探日志 traceId 未传播到另一个服务

Posted 2023-02-16

【中文标题】侦探日志 traceId 未传播到另一个服务

【英文标题】：Sleuth log traceId not propagated to another service

【发布时间】：2017-08-31 00:49:25

【问题描述】：

我尝试在我的微服务中添加分布式跟踪（在 Azure 中的 Kubernetes 下）。

我在父 pom.xml 中添加了依赖项：

<parent>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-parent</artifactId>
    <version>1.4.1.RELEASE</version>
    <relativePath/>
</parent>
<dependencies>
    ...
    <dependency>
        <groupId>org.springframework.cloud</groupId>
        <artifactId>spring-cloud-sleuth-core</artifactId>
        <version>1.1.3.RELEASE</version>
    </dependency>
    <dependency>
        <groupId>org.springframework.cloud</groupId>
        <artifactId>spring-cloud-sleuth-zipkin</artifactId>
        <version>1.1.3.RELEASE</version>
    </dependency>
</dependencies>
<dependencyManagement>
    <dependencies>
        <dependency>
            <groupId>org.springframework.cloud</groupId>
            <artifactId>spring-cloud-dependencies</artifactId>
            <version>CAMDEN.SR4</version>
            <type>pom</type>
            <scope>import</scope>
        </dependency>
        ...
    </dependencies>
</dependencyManagement>

我使用 1.4.1 和 CAMDEN.SR4，因为 fabric8 kubeflix 不支持更新的版本。我强制 1.1.3.RELEASE 尝试最新的 sleuth 版本，看看它是否是旧版本 sleuth 的错误。

我使用 logback-spring.xml 的这个配置：

<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <springProperty scope="context" name="springAppName" source="spring.application.name"/>
    <jmxConfigurator/>
    <property name="CONSOLE_LOG_PATTERN"
          value="%dyyyy-MM-dd HH:mm:ss.SSS [$springAppName,%XX-B3-TraceId:-,%XX-B3-SpanId:-,%XX-Span-Export:-] [%thread] %-5level %logger35 - %msg%n"/>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>$CONSOLE_LOG_PATTERN</pattern>
        </encoder>
    </appender>
    <root level="DEBUG">
        <appender-ref ref="STDOUT"/>
    </root>
    <logger name="org.springframework" level="ERROR"/>
    <logger name="com.netflix" level="ERROR"/>
    <logger name="io.fabric8" level="ERROR"/>
    <logger name="org.apache" level="ERROR"/>
</configuration>

这是我的 application.yml ：

spring:
  zipkin:
    baseUrl: http://zipkin:8080
  sleuth:
    sampler:
      percentage: 1.0
server:
  port: 8080

zipkin URL 是暴露 Zipkin 服务器的 Kubernetes 服务（带有 @EnableZipkinServer 的 Spring boot 应用）

然后我用这段代码调用第一个服务（services-1）：

private RestTemplate template = new RestTemplate();

@GetMapping("/key/language")
public String getLabel(@PathVariable String key, @PathVariable String language) throws UnknownHostException 
    log.info("Entering getLabel");
    String testResponse = template.getForObject("http://services-i18n-2/test", String.class);
    String s = labelService.getLabel(key, language) + " " + message + " " + InetAddress.getLocalHost().getHostName() + ", response=" + testResponse;
    log.info("Exiting getLabel");
    return s;

产生这些日志：

2017-04-05T11:04:48.497345669Z 2017-04-05 11:04:48.497 [services-1,eaf3dbcb2f92091b,95dd9e6082990923,false] [XNIO-2 task-4] INFO  c.l.m.i18n.web.LabelController - Entering getLabel
2017-04-05T11:04:48.519851116Z 2017-04-05 11:04:48.519 [services-1,eaf3dbcb2f92091b,95dd9e6082990923,false] [XNIO-2 task-4] DEBUG c.l.m.i18n.service.LabelService - Response Label(key=Key(value=action.login), language=Language(value=fr), value=s'authentifier)
2017-04-05T11:04:48.519864516Z 2017-04-05 11:04:48.519 [services-1,eaf3dbcb2f92091b,95dd9e6082990923,false] [XNIO-2 task-4] INFO  c.l.m.i18n.web.LabelController - Exiting getLabel

如您所见，它使用 RestTemplate 调用 services-i18n-2 服务，生成以下日志：

2017-04-05T11:04:48.514145894Z 2017-04-05 11:04:48.513 [services-2,e0c6495a0a598cff,e0c6495a0a598cff,true] [XNIO-2 task-4] INFO  c.l.m.i18n.web.TestController - Entering test
2017-04-05T11:04:48.516430459Z 2017-04-05 11:04:48.516 [services-2,e0c6495a0a598cff,e0c6495a0a598cff,true] [XNIO-2 task-4] INFO  c.l.m.i18n.web.TestController - Exiting test

如您所见，service-2 (e0c6495a0a598cff) 中的 traceId 与 service-1 (eaf3dbcb2f92091b) 不同。

在 service-2 中，traceId 与 spanId 相同。

问题：

为什么我没有将 traceId 传播到 service-2 以便能够在 Zipkin 中查看完整的堆栈跟踪？ 为什么 service-2 中的 traceId 等于 spanId ？ 为什么 exportable 在 service-1 中是假的？ Zipkin 服务器看不到这些日志。 我在 Zipkin 服务器中收到了 rxjava spans 的垃圾邮件。我已经尝试过 spring.sleuth.rxjava.schedulers.ignoredthreads=rxjava 但它仍然适用于 Zipkin。

仅供参考，我在依赖项中有 Hystrix，我已删除 @HystrixCommand 以确保 Hystrix 在每次 HTTP 调用时创建新的 traceId 没有问题。

【参考方案1】：

对于 1、2、3 是因为我在做一个新的 RestTemplate。

文档说：

您必须将 RestTemplate 注册为 bean，以便拦截器被注入。如果您使用新关键字创建 RestTemplate 实例，则检测将不起作用。

所以我自己的 RTFM，这解决了我的前 3 个问题：

@Bean
public RestTemplate template() 
    return new RestTemplate();

@Autowired
private RestTemplate template;

【讨论】：

对于 4。我结束添加 spring.sleuth.rxjava.schedulers.hook.enabled=false 但我不是它的忠实粉丝。