dubbo分布式日志调用链追踪

一、背景

任何系统都无法100%保证不出错误，线上系统报错之后，首先要做的就是在第一时间内找出问题，解决问题，定位线上问题最主要的途径就是看日志。

在单模块下根据日志排查问题，只需要直接搜索关键字就能很清晰地看到线上代码的执行情况。而随着现在越来越多的系统分布式化、微服务化，一个请求往往需要经过多个分布式模块协同处理，比如下面这个简单的分布式系统，购买一件商品的流程大致为：在web/h5/app端发送下单请求到网关(gateway)；网关对请求进行过滤、包装，转发到业务模块(business)；业务模块执行相关业务，在此需要根据具体业务逻辑调用用户模块(user)查询用户相关信息如用户名、收件地址等；调用商品模块(goods)查询商品信息如库存等；调用订单模块(order)生成订单；调用账务模块(account)查询优惠券等。

在这样的系统中，一旦下单失败，想要查看代码详细执行的情况，就得一个一个查看每个模块的日志，而且查找的关键字也可能不一样，比如查询用户模块的日志用用户名当关键字，查询商品模块用商品编码当关键字……这就很麻烦了。

二、分布式日志调用链追踪介绍

要解决上面的问题，可以在请求入口（比如上图中的网关模块gateway，甚至web/h5/app都可以）针对每一个请求生成一个requestId，后面整个执行链路中都带着这个requestId，利用这个requestId可以把整个过程中打出的相关日志连成一个串。当出现问题之后，在任意模块根据关键字找出requestId，如果相关模块部署在同一台机器上，可以利用tail -f 日志文件1.log 日志文件2.log 日志文件3.log |grep 'requestId的值'之类的方式查看调用链路的日志，比如查看一个用户登录时，在gateway、business、user模块打印的日志：

当然有ELK的话也可以通过ELK来查看。

三、分布式日志调用链追踪实现

以上只是一个把分布式日志“串”起来的一个思路，技术架构、部署方式不同的项目，具体实现方式肯定也不同。这里以以SpringBoot(Spring)+Dubbo为基础的系统来介绍一种实现方法。

1、在gateway模块生成requestId

首先需要在gateway模块生成一个requestId字符串，因为gateway模块调用business模块是通过dubbo调用，所以可以通过传参把requestId传递到business模块，但是这样对代码的入侵太严重了，服务调用者每次调用dubbo服务都需要把requestId放到参数中，所以这种方法pass掉！

这个问题，Dubbo的开发者们早就想到了，可以利用Dubbo的Filter来实现。

（1）首先在gateway模块的全局过滤器（自己实现的javax.servlet.Filter）中生成一个requestId字符串（尽量不重复），放到ThreadLocal（为了在gateway模块的其他地方打印日志时随用随取）中：

//定义一个全局静态的ThreadLocal
public static ThreadLocal requestIdThreadLocal = new NamedThreadLocal("requestId");


//把生成的requestId放到ThreadLocal中
String requestId=UUID.randomUUID().toString();
requestIdThreadLocal.set(requestId)
1
2
3
4
5
6
7

同时也放到dubbo的上下文中：

//定义一个Map，只能是Map类型，可以存放一些字符类型的信息，比如dubbo调用者要向dubbo提供者传送的requestId
Map context = new HashMap();
context.put("requestId", requestId);
//把存储有requestId的map放到Dubbo的上下文中
RpcContext.getContext().setAttachments(context);
1
2
3
4
5

这时gateway模块在打印日志时（无论是配置的AOP，还是嵌入在代码里的日志），都可以直接从ThreadLocal中获取requestId。

（2）gateway模块（dubbo调用者）已经把requestId放到dubbo的Context中了，接下来就需要在business模块（dubbo提供者）从Context中获取requestId，怎么获取呢？用Dubbo的Filter来获取。

① 定义一个全局静态的ThreadLocal,为了在business模块其他地方打印日志时随用随取：

public static ThreadLocal requestIdThreadLocal = new NamedThreadLocal("requestId");
1

② 建一个实现com.alibaba.dubbo.rpc.Filter的过滤器，从dubbo的Context中接收requestId并放到ThreadLocal中：

public class DubboContextFilter implements Filter {
    @Override
    public Result invoke(Invoker invoker, Invocation invocation) throws RpcException {
        Map context = RpcContext.getContext().getAttachments();
        String requestId=context.get("requestId");
        requestIdThreadLocal.set(requestId);
        return invoker.invoke(invocation);
    }
}
1
2
3
4
5
6
7
8
9

③ 在配置文件的根目录（resources目录）建立名为META-INF.dubbo的文件夹，文件夹里建立名为com.alibaba.dubbo.rpc.Filter的文件，内容为：
“dubboContextFilter=DubboContextFilter的全路径类名”，比如：

dubboContextFilter=com.happycommunity.business.config.DubboContextFilter
1

④ 在Dubbo提供者的实现类的@com.alibaba.dubbo.config.annotation.Service注解中添加属性filter = “dubboContextFilter”。

这时business模块在打印日志时（无论是配置的AOP，还是嵌入在代码里的日志），都可以直接从ThreadLocal中获取requestId。

其他模块也一样，Dubbo服务的调用者把requestId放到Dubbo的Context中，Dubbo服务的提供者通过Dubbo的Filter从Context中获取requestId并存入ThreadLocal，画了个图流程大概如图所示：

上图中箭头指的就是requestId传递的路线。在gateway模块中，Servlet Filter拦截HTTP请求，对每个外部的请求生成一个requestId，存入ThreadLocal和Dubbo的Context，因为在同一个JVM中，该次请求执行的操作是都在一个线程中，在gateway模块的任意位置打日志都可以直接从ThreadLocal中获取requestId。

当Dubbo服务请求到business模块时，因为不在一个JVM中，就不能直接跟gateway模块似的直接从ThreadLocal中获取requestId了，所以需要用Dubbo的Filter在接收到Dubbo请求之后，执行方法之前，从Context中获取到requestId并存入当前线程（business接收到gateway的dubbo请求后重新开启了一个新的线程来处理业务逻辑）的ThreadLocal中，后续在任意位置打日志都可以直接从ThreadLocal中获取requestId。

(注：上文中的代码仅为示例代码，并不完整，完整的demo可参考：https://github.com/DannyHoo/happycommunity)