分布式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中中以便给开发和运维同学查询使用。