分布式Trace

六、分布式Trace简述

1. 请求要在多个服务之间调用，如何排查慢请求问题？

给同一个请求的每一行日志增加一个相同的标记，比如我们可以在程序的入口处生成一个requestId，然后把它放在线程的上下文中，这样就可以在需要时随时从线程上下文中获取到requestId了。

String requestId = UUID.randomUUID().toString();
ThreadLocal tl = new ThreadLocal(){
    @Override
    protected String initialValue() {
        return requestId;
    }
}; //requestId存储在线程上下文中
long start = System.currentTimeMillis();
processA();
Logs.info("rid : " + tl.get() + ", process A cost " + (System.currentTimeMillis() - start)); // 日志中增加requestId
start = System.currentTimeMillis();
processB();
Logs.info("rid : " + tl.get() + ", process B cost " + (System.currentTimeMillis() - start));
start = System.currentTimeMillis();
processC();
Logs.info("rid : " + tl.get() + ", process C cost " + (System.currentTimeMillis() - start));

2. 如何完成集中日志打印？

可以通过切面编程来实现，一般来说，切面编程的实现分为两类：

• 一类是静态代理，典型的代表是AspectJ，它的特点是在编译期做切面代码注入；编译期插入代码完毕之后在运行期就基本对于性能没有影响。
• 另一类是动态代理，典型的代表是Spring AOP，它的特点是在运行期做切面代码注入。在运行期需要生成代理对象，所以动态代理的性能要比静态代理要差。

@Aspect
public class Tracer {
    @Around(value = "execution(public methodsig)", argNames = "pjp") //execution内替换要做切面的方法签名
    public Object trace(ProceedingJoinPoint pjp) throws Throwable {
        TraceContext traceCtx = TraceContext.get(); //获取追踪上下文，上下文的初始化可以在程序入口处
        String requestId = reqCtx.getRequestId(); //获取requestId
        String sig = pjp.getSignature().toShortString(); //获取方法签名
        boolean isSuccessful = false;
        String errorMsg = "";
        Object result = null;
        long start = System.currentTimeMillis();
        try {
            result = pjp.proceed();
            isSuccessful = true;
            return result;
        } catch (Throwable t) {
            Logs.info(errorMsg);
        } finally {
            long elapseTime = System.currentTimeMillis() - start;
            Logs.info("rid : " + requestId + ", start time: " + start + ", elapseTime: " + elapseTime + ", sig: " + sig + ", isSuccessful: " + isSuccessful + ", errorMsg: " + errorMsg  );
        }
    }

}

3.横跨几十个分布式组件的慢请求要如何排查？

答：分布式Trace

分布式请求问题：单次请求的所有的耗时日志都被记录在一台服务器上，而在微服务的场景下，单次请求可能跨越多个RPC服务，这就造成了单次的请求的日志会分布在多个服务器上，仅仅依靠requestId很难表达清楚服务之间的调用关系，所以从日志中就无法了解服务之间是谁在调用谁。

解决思路：采用traceId + spanId这两个数据维度来记录服务之间的调用关系（这里traceId就是requestId），也就是使用traceId串起单次请求，用spanId记录RPC调用之间的关系。

• 首先，A服务在发起RPC请求服务B前，先从线程上下文中获取当前的traceId和spanId，然后依据上面的逻辑生成本次RPC调用的spanId，再将spanId和traceId序列化后装配到请求体中，发送给服务方B。

• 服务方B获取请求后，从请求体中反序列化出spanId和traceId，同时设置到线程上下文中，以便给下次RPC调用使用。在服务B调用完成返回响应前，计算出服务B的执行时间发送给消息队列。

• 当然，在服务B中，你依然可以使用切面编程的方式将得到所有调用的数据库、缓存、HTTP服务的响应时间等日志信息发送给消息队列，只是在发送给消息队列的时候，要加上当前线程上下文中的spanId和traceId。

• 这样，无论是数据库等资源的响应时间，还是RPC服务的响应时间等信息就都汇总到了消息队列中，在经过一些处理之后，最终被写入到Elasticsearch或Hive中中以便给开发和运维同学查询使用。

4. 如何有效管理大量日志？

随着业务量的提升，如果每个接口中打印出了所有访问数据库、缓存、外部接口的耗时情况，一次请求可能要打印十几条日志，如果你的电商系统的QPS是10000的话，就是每秒钟会产生十几万条日志，对于磁盘I/O的负载是巨大的。

解决思路：

把日志不打印到本地文件中，而是发送到消息队列里，再由消息处理程序写入到集中存储中，比如Elasticsearch，Hive表。这样，你在排查问题的时候，只需要拿着TraceId到Elasticsearch中查找相关的记录就好了。

具体实现：

数据从原始日志到hive的流程做下整体的概括

从图1可以看出，系统的关键流程有三步：

1. 客户端应用接入XMD日志，并上报日志信息到数据平台
2. 数据平台完成kafka消息到数据仓库hive表的转换(如果只需要hive表，可跳过第3步)
3. 通过数仓聚合ETL和同步任务把hive表的聚合数据同步到MySQL表

得到hive表，我们就可以做一些更加灵活的控制。如在XT平台上通过ETL任务对该表进行如聚合、导出、同步等操作。当然，如果不需要同步数据到MySQL，整个流程只需要走到第2步，使用hive取数即可！

其中，第1、2步更详细的原理流程展开如图2所示：

[1] 日志上报kfka再到hive