背景
目前,微服务和分布式服务架构在互联网公司被普遍应用,在国内阿里dubbo用的比较多,但是,dubbo只是一个rpc框架,缺乏全链路追踪组件,并不像springcloud是一个生态,包含了各种分布式组件。
我们公司也是用dubbo,分布式服务虽然解决了水平扩展的问题,但是却又带来了其他新的问题,比如链路追踪这一块,如果是单体应用,所有的日志都在一个项目,现在是服务集群,各个服务之间的调用关系是错综复杂的,同一个服务具体是走的哪一个机器,是根据负载均衡算法路由的,所以不好查日志。哪怕是用了elk中心化日志系统,由于同一时间并发请求数量比较高,不同的请求日志都混在一起,所以最好可以做到链路追踪,尤其是全链路追踪,即不仅仅是在同一个项目找到当前线程的所有日志,而且还要在不同项目之间找到同一个请求的所有日志。
有了全链路追踪,就可以把分布式服务的每个服务节点串起来,从而更好的排查故障和监控系统。
具体实现原理是基于业界普遍的分布式追踪id,即把唯一的分布式追踪id从入口处,一直往下传递,最后每个服务的日志都包含了该分布式服务追踪id。
线程内和跨进程
要解决两大问题,
1、解决同一个进程内的同一个线程的链路追踪
基于java线程本地变量ThreadLocal实现。
2、解决跨进程的链路追踪
即在dubbo的服务消费者和服务提供者之间传递链路id,基于dubbo上下文RpcContext实现。
架构图
核心设计思想
1、进程内的线程链路追踪
所谓进程内,就是指服务消费者或服务提供者内部的链路追踪,实现原理是基于
1)扩展日志框架(比如logback)的功能
2)每次打印日志的时候,自动携带链路id
2、跨进程的链路追踪
所谓跨进程,就是指服务消费者和服务提供者是两个运行在不同机器的进程,实现原理是基于:
1)自定义dubbo拦截器
实现dubbo的Filter接口;
根据当前请求线程的所在进程是服务消费者还是服务提供者,分表做不同的业务逻辑处理。
2)服务消费者
写数据到日志ThreadLocal;
在拦截器里,写数据到dubbo上下文RpcContext。
3)服务提供者
在拦截器,从dubbo上下文RpcContext读数据;
写数据到日志ThreadLocal。
总结
1、基于ThreadLocal,实现线程链路追踪。
2、基于dubbo的扩展功能,实现跨进程链路追踪,每个进程都要引入链路追踪功能才能实现全链路追踪。
3、链路追踪id被写在每个日志的日志戳字段里,通过在elk中心化日志系统里搜索链路Id,就可以搜索到一个请求的完整日志信息。
链路id日志戳字段,需要自己扩展日志框架功能,比如可以基于slf + logback实现。
代码
跨进程
自定义扩展dubbo拦截器
/**
* dubbo日志拦截器,作用
1.打印消费者和提供者的入参和响应
基于dubbo拦截器实现
2.全链路追踪
基于日志拦截器(线程本地变量)和dubbo上下文实现。(注:全链路追踪的每个服务,都要配置该拦截器,才能实现全链路追踪)
*/
@Activate(group = {Constants.PROVIDER, Constants.CONSUMER})
public class AccessLogExtFilter implements Filter {
public Result invoke(Invoker<?> invoker, Invocation inv) throws RpcException {
...
handleTraceNo();
...
}
/**
* 在消费者和提供者之间传递日志戳-流水号数据,用于链路追踪
*/
private void handleTraceNo() {
boolean isConsumer = RpcContext.getContext().isConsumerSide();
if (isConsumer) { //如果是消费者,写数据到dubbo上下文
RpcContext.getContext()
.setAttachment("xxx_TRACE_NO", LogPreFixConverter.getCurrentThreadLogPreFix(""));
} else { //如果是提供者,从dubbo上下文读数据
String traceNo = RpcContext.getContext().getAttachment("xxx_TRACE_NO");
if (StringUtils.isBlank(traceNo)) { //如果消费者没有设置流水号,就随机生成
traceNo = UUID.randomUUID().toString();
}
LogPreFixConverter.setLogPreFixNoAppendThread(traceNo);
}
}
线程内
扩展日志框架logback
1)自定义字段
日志配置文件
<!-- 统一日志格式输出用|分隔方便 elk日志工具收集处理 ,默认日志格式是 时间|级别|日志戳|代码路径|扩展json(收集图表数据,无则域留空)|脱敏后日志内容 -->
<property name="logback.pattern"
value="%date{yyyy-MM-dd HH:mm:ss.SSS}|%-5level|%logPreFix|%class.%method:%line|%extjson|%sensitiveMsg%n" />
logPreFix是自定义字段/日志戳/全链路id。
2)实现自定义字段处理类
public class LogPreFixConverter extends ClassicConverter {
private static final ThreadLocal<String> logPreFixThreadLocal = new ThreadLocal<String>(); //这里的实现比较复杂一点,基于线程本地变量实现全链路跟踪。
@Override
public String convert(ILoggingEvent event) { //这个方法的作用,就是映射字段变量和字段变量的值
try {
return getCurrentThreadLogPreFix(event.getFormattedMessage());
} catch (Throwable t) {
// TODO 处理异常,这时不应该再打印日志避免死循环
System.err.println("LogPreFixConverter处理异常" + t.getMessage());
}
return "errorLogPreFix";
}
/**
* 获取线程局部日志前辍
*
* @param msg
* 优先通过入口日志中查找orderid tradesn 等关键字来做为前辍,如果没找到则默认生成一个
* @return
*/
public String getCurrentThreadLogPreFix(String msg) {
String logPreFixStr = logPreFixThreadLocal.get();
if (StringUtils.isBlank(logPreFixThreadLocal.get())) {
// key:value value可能为空(字符串开头有空格会受影响忽略,目前通过format方法时trim);
// 可能以空格结束,可能为最后一个字符结束
String rexp = "(orderid|tradesn|batchid):(\\s|.+?(\\s|.$))";
// 忽略大小写查找到key:value数据据
Pattern pattern = Pattern.compile(rexp, Pattern.CASE_INSENSITIVE);
Matcher matcher = pattern.matcher(msg);
if (matcher.find()) {
// 得到key:value
logPreFixStr = matcher.group();
// 得到value ,如果value是json 替换掉"
logPreFixStr = logPreFixStr.substring(
logPreFixStr.indexOf(":") + 1).replace("\"", "");
}
if (StringUtils.isBlank(logPreFixStr)) {
logPreFixStr = generateId(12);
}
// 增加线程id
logPreFixStr = new StringBuilder().append(logPreFixStr).append("-")
.append(Thread.currentThread().getId()).toString();
logPreFixThreadLocal.set(logPreFixStr);
}
return logPreFixStr;
}