有了这款工具，定位线上问题事半功倍｜云效工程师指北

2022 年 4 月 07 日
本文字数：3477 字
阅读完需：约 11 分钟

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

焦头烂额的一天

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

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

寻求解决问题的方案

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

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

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

改造系统

期望的效果

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

用户请求遇到问题时候，可以获取到一个 traceId，只要提供了这个 traceId，就可以看到这个请求在各个服务之间的调用路径。并且可以通过这个 traceId 查到所有应用中相关的日志。
当收到 RT 告警时，也能够从 Nginx 的日志中找到这个 traceId。

接入链路追踪

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

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

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

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

由于小张的系统是基于 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;
@TraceCrossThreadpublic 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;
@TraceCrossThreadpublic 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 执行出现异常。