一、背景
任何系统都无法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模块的其他地方打印日志时随用随取)中:
代码语言:javascript复制//定义一个全局静态的ThreadLocal
public static ThreadLocal<String> requestIdThreadLocal = new NamedThreadLocal<String>("requestId");
代码语言:javascript复制//把生成的requestId放到ThreadLocal中
String requestId=UUID.randomUUID().toString();
requestIdThreadLocal.set(requestId)
同时也放到dubbo的上下文中:
代码语言:javascript复制//定义一个Map,只能是Map<String, String>类型,可以存放一些字符类型的信息,比如dubbo调用者要向dubbo提供者传送的requestId
Map<String, String> context = new HashMap<String, String>();
context.put("requestId", requestId);
//把存储有requestId的map放到Dubbo的上下文中
RpcContext.getContext().setAttachments(context);
这时gateway模块在打印日志时(无论是配置的AOP,还是嵌入在代码里的日志),都可以直接从ThreadLocal中获取requestId。
(2)gateway模块(dubbo调用者)已经把requestId放到dubbo的Context中了,接下来就需要在business模块(dubbo提供者)从Context中获取requestId,怎么获取呢?用Dubbo的Filter来获取。
① 定义一个全局静态的ThreadLocal,为了在business模块其他地方打印日志时随用随取:
代码语言:javascript复制public static ThreadLocal<String> requestIdThreadLocal = new NamedThreadLocal<String>("requestId");
② 建一个实现com.alibaba.dubbo.rpc.Filter的过滤器,从dubbo的Context中接收requestId并放到ThreadLocal中:
代码语言:javascript复制public class DubboContextFilter implements Filter {
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
Map<String, String> context = RpcContext.getContext().getAttachments();
String requestId=context.get("requestId");
requestIdThreadLocal.set(requestId);
return invoker.invoke(invocation);
}
}
③ 在配置文件的根目录(resources目录)建立名为META-INF.dubbo的文件夹,文件夹里建立名为com.alibaba.dubbo.rpc.Filter的文件,内容为: “dubboContextFilter=DubboContextFilter的全路径类名”,比如:
代码语言:javascript复制dubboContextFilter=com.happycommunity.business.config.DubboContextFilter
④ 在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)