有了这款工具，定位线上问题事半功倍

刘玄阿里云云栖号 2022-07-13

作者｜刘玄

文章来源｜阿里巴巴云效团队

大家好，我叫刘玄，负责云效流水线的开发。程序员在日常工作中经常会遇到一些线上问题需要排查，本文的主人公程序员小张也不例外。但排查的过程却时常令他困扰不已。让我们一起看看他遇到了哪些问题，又是怎么解决的。

焦头烂额的一天

那是一个阳光明媚的上午，小张来到工位，打开电脑，备上咖啡，精神满满的开始了一天的工作。正在小张噼里啪啦的敲着键盘，认真Coding之时，钉钉群里的一个钉，打破了宁静。客服人员反馈，有客户遇到了一个问题，需要开发人员排查。小张排查了线上日志，发现用户的请求比较多，日志也比较多，没有定位到关键信息。小张只能又让客服找用户提供更具体的信息。在和用户反复进行沟通之后，小张最终花了半个多小时才定位到了问题。

忙碌的一天很快结束，正当小张准备下班，筹划着下班之后怎么happy时，电话报警的声音，又把他拉回了现实。小张收到后端服务RT高的告警后，赶紧排查多个后台应用的监控信息和日志。虽然很快从Nginx日志定位到了有问题的请求信息，但小张很难精确的找到这个请求对应的应用日志，所以花费了很长时间才定位到问题：一个第三方服务异常，导致部分功能受影响。定位到原因后，及时采取了降级手段，系统恢复正常。

寻求解决问题的方案

过完了焦头烂额的一天，小张觉得现在处理问题的效率太低，大把的时间花在了问题定位上。而之所以排查的这么慢，是因为系统采用微服务架构，一个请求会涉及到多个服务，并且每个服务还会调用DB、缓存以及其他第三方服务。大致链路如下：

小张想，应该有成熟的技术方案，能够标识整个请求链路，将异常服务节点清晰标注。小张借助搜索工具，发现有一种解决方案，链路追踪，刚好适合自己的场景。

链路追踪工具可以将一次分布式请求还原成完整的调用链路，将整个请求的调用情况进行展示，比如各个服务上的耗时、各个服务的请求状态、具体调度到各个服务的哪台机器上等信息。

改造系统

期望的效果

根据前面遇到的两个问题，小张期望：

1. 用户请求遇到问题时候，可以获取到一个traceId，只要提供了这个traceId，就可以看到这个请求在各个服务之间的调用路径。并且可以通过这个traceId查到所有应用中相关的日志。

2. 当收到RT告警时，也能够从Nginx的日志中找到这个traceId。

接入链路追踪

经过技术选型，小张选择阿里云的产品链路追踪Tracing Analysis作为自己链路追踪的服务端。

阿里云链路追踪Tracing Analysis提供了完整的调用链路还原、调用请求量统计、链路拓扑、应用依赖分析等工具，可以帮助用户快速分析和诊断分布式应用架构下的性能瓶颈，提高微服务时代下的开发诊断效率。

阿里云链路追踪Tracing Analysis支持多种常见的链路追踪工具，例如Zipkin、Skywalking、Jaeper等。小张选择使用Skywalking作为链路追踪数据埋点。

在阿里云上开通完链路追踪Tracing Analysis 产品之后，就可以在集群配置中获取到Skywalking的接入点。更详细的接入指南参考阿里云官方文档。

https://help.aliyun.com/document_detail/104185.html

由于小张的系统是基于spring boot，所以只需要在启动命令中加入以下内容即可。

-DSW_AGENT_COLLECTOR_BACKEND_SERVICES=<Tracing Analysis上的接入点>"
-DSW_AGENT_NAME=<Tracing Analysis的应用名称>"
-javaagent:skywalking-agent.jar=<Tracing Analysis的authentication信息>"

重新启动应用后，链路追踪埋点数据就会收集到链路追踪Tracing Analysis 上了。

日志中打印traceId

为了能够通过traceId搜索到所有的日志，也需要在的应用的日志中展示traceId信息，具体方式如下：

在应用中引入以下依赖：

<dependency>
    <groupId>org.apache.skywalking</groupId>
    <artifactId>apm-toolkit-logback-1.x</artifactId>
    <version>6.6.0</version>
</dependency>

修改logback配置文件，例如：tid即为 Skywalking 的traceId。

<property name="LOG_PATTERN" value="[%d{'yyyy-MM-dd HH:mm:ss,SSS',GMT+8:00}] %-5p [%.10t][%X{CU}][%X{tid}]    %logger{36}[%L] - %m%n"/>
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
        <layout class="org.apache.skywalking.apm.toolkit.log.logback.v1.x.mdc.TraceIdMDCPatternLogbackLayout">
            <pattern>${LOG_PATTERN}</pattern>
        </layout>
    </encoder>
</appender>

以上改动就可以在日志中看到traceId了。如下图所示：图中标红的TID值即为traceId。

同时小张也在系统出现异常信息时，将traceId透出给用户，用户反馈问题时只需要提供traceId即可。相应的，需要在代码中把traceId写入到响应体中，如下所示：

String traceId = TraceContext.traceId();
result.setTraceId(traceId);

Nginx日志中打印traceId

为了在收到系统RT告警时，也可以获得traceId，需要修改Nginx配置。

接入Skywalking之后，系统间调用的请求都会带上名称为sw6的header (其中6为对应的Skywalking版本号)，Header值的的格式为：1-TRACEID-SEGMENTID-3-PARENT_SERVICE-PARENT_INSTANCE-PARENT_ENDPOINT-IPPORT

从这个值中提取出TRACEID，也就是第一个和第二个横杠之间的部分，再进行BASE64 decode就可以获取到traceId。

然后需要在Nginx 的log_format 配置添加对应的Header，如下如下：

log_format main 'http_sw6:$http_sw6; http_ns_client_ip:$http_ns_client_ip; time_local:$time_local; request_time:$request_time; upstream_response_time:$upstream_response_time; request:$request_method http://$host$request_uri; request_length:$request_length; upstream_cache_status:$upstream_cache_status; httpStatus:$status; body_bytes_sent:$body_bytes_sent; http_referer:$http_referer; http_user_agent:$http_user_agent; http_x_forwarded_for:$http_x_forwarded_for; remote_addr:$remote_addr;';

然后就可以在Nginx日志中看到了相应的值了，如图：

解决链路追踪多线程丢失traceId的问题

小张在测试链路追踪时，发现在多线程的使用场景中，只有一个子线程能够正确获取到traceId，而其它线程中的traceId会出现丢失。为了解决上述问题，小张使用@TraceCrossThread注解对Callable和Runnable进行增强，

@TraceCrossThread为Skywalking提供的注解,Skywalking通过增强被此注解注释的类，以此来实现traceId的跨线程传递。示例代码如下。

import org.apache.skywalking.apm.toolkit.trace.TraceCrossThread;

@TraceCrossThread
public class TraceableRunnable implements Runnable {

    private final Runnable runnable;

    public TraceableRunnable(final Runnable runnable) {
        this.runnable = runnable;
    }

    @Override
    public void run() {
       runnable.run();
    }
}

import java.util.concurrent.Callable;
import org.apache.skywalking.apm.toolkit.trace.TraceCrossThread;

@TraceCrossThread
public class TraceableCallable<T> implements Callable<T> {

    private final Callable<T> callable;

    public TraceableCallable(final Callable<T> callable) {
        this.callable = callable;    
    }

    @Override
    public T call() throws Exception {
         return callable.call();
    }
}

‍

后续提交线程任务时使用改造后的TraceableCallable和TraceableRunnable 即可解决多线程丢失traceId 的问题。

完成以上改造后，以下图为例，用户每一次的请求都会有对应的traceId，便于将整个请求链路展示出来。

轻松应对线上问题

又一个阳光明媚的早上，小张埋头工作时，又有客服反馈用户问题，这个时候小张不慌不忙的根据用户提供traceId，在阿里链路追踪https://tracing.console.aliyun.com/上查看调用链路，很快定位到异常节点，示例如下：图中状态为红色的节点就是异常节点，图中示例表示由于某个sql执行出现异常。

轻松应对一天工作后，小张在下班前又收到应用RT过高的告警，由于Nginx日志中打印了traceId信息，很快就可以定位到耗时的请求，示例如下：

图中耗时比较长的节点，是由于调用第三方服务造成，小张根据情况，对服务进行降级，很快就解决RT过高的问题，防止问题扩散。

接入了链路追踪以后，小张在定位线上问题的耗时大大缩短，可以有更多的时间专注其他工作。

以上就是小张是如何通过使用链路追踪从焦头烂额的排查线上问题到从容定位线上问题的转变，希望对仍未使用链路追踪技术的同学有些帮助。本故事纯属虚构，如有雷同，纯属巧合。

云栖号的伙伴群开启了，欢迎大家入群聊起来！

大家想看什么内容，我们可以一起聊聊～

👇👇👇

✨ 精彩推荐✨

技术好文