Dubbo-全链路追踪日志的实现

共计 4904 个字符，预计需要花费 13 分钟才能阅读完成。

微服务架构的项目，一次请求可能会调用多个微服务，这样就会产生多个微服务的请求日志，当我们想要查看整个请求链路的日志时，就会变得困难，所幸的是我们有一些集中日志收集工具，比如很热门的 ELK，我们需要把这些日志串联起来，这是一个很关键的问题，如果没有串联起来，查询起来很是很困难，我们的做法是在开始请求系统时生成一个全局唯一的 id，这个 id 伴随这整个请求的调用周期，即当一个服务调用另外一个服务的时候，会往下传递，形成一条链路，当我们查看日志时，只需要搜索这个 id，整条链路的日志都可以查出来了。

现在以 dubbo 微服务架构为背景，举个栗子：

A -> B -> C

我们需要将 A /B/C/ 三个微服务间的日志按照链式打印，我们都知道 Dubbo 的 RpcContext 只能做到消费者和提供者共享同一个 RpcContext，比如 A ->B，那么 A 和 B 都可以获取相同内容的 RpcContext，但是 B ->C 时，A 和 C 就无法共享相同内容的 RpcContext 了，也就是无法做到链式打印日志了。

那么我们是如何做到呢？

我们可以用左手交换右手的思路来解决，假设左手是线程的 ThreadLocal，右手是 RpcContext，那么在交换之前，我们首先将必要的日志信息保存到 ThreadLocal 中。

在我们的项目微服务中大致分为两种容器类型的微服务，一种是 Dubbo 容器，这种容器的特点是只使用 spring 容器启动，然后使用 dubbo 进行服务的暴露，然后将服务注册到 zookeeper，提供服务给消费者；另一种是 SpringMVC 容器，也即是我们常见的 WEB 容器，它是我们项目唯一可以对外开放接口的容器，也是充当项目的网关功能。

在了解了微服务容器之后，我们现在知道了调用链的第一层一定是在 SpringMVC 容器层中，那么我们直接在这层写个自定义拦截器就 ojbk 了，talk is cheap，show you the demo code：

举例一个 Demo 代码，公共拦截器的前置拦截中代码如下：

public class CommonInterceptor implements HandlerInterceptor {
    @Override
    public boolean preHandle(HttpServletRequest httpServletRequest, HttpServletResponse httpServletResponse, Object handler)
        throws Exception {

        // ...

        // 初始化全局的 Context 容器
        Request request = initRequest(httpServletRequest);
        // 新建一个全局唯一的请求 traceId，并 set 进 request 中
        request.setTraceId(JrnGenerator.genTraceId());
        // 将初始化的请求信息放进 ThreadLocal 中
        Context.initialLocal(request);

        // ...

        return true;
    }
    
    // ...
    
}

系统内部上下文对象：

public class Context {
    
    // ...
    
    private static final ThreadLocal<Request> REQUEST_LOCAL = new ThreadLocal<>();
    
    public final static void initialLocal(Request request) {if (null == request) {return;}
        REQUEST_LOCAL.set(request);
    }
    
    public static Request getCurrentRequest() {return REQUEST_LOCAL.get();
    }
    
    // ...
}

拦截器实现了 org.springframework.web.servlet.HandlerInterceptor 接口，它的主要作用是用于拦截处理请求，可以在 MVC 层做一些日志记录与权限检查等操作，这相当于 MVC 层的 AOP，即符合横切关注点的所有功能都可以放入拦截器实现。

这里的 initRequest(httpServletRequest); 就是将请求信息封装成系统内容的请求对象Request，并初始化一个全局唯一的 traceId 放进 Request 中，然后再把它放进系统内部上下文 ThreadLocal 字段中。

接下来讲讲如何将 ThreadLocal 中的内容放到 RpcContext 中，在讲之前，我先来说说 Dubbo 基于 spi 扩展机制，官方文档对拦截器扩展解释如下：

服务提供方和服务消费方调用过程拦截，Dubbo 本身的大多功能均基于此扩展点实现，每次远程方法执行，该拦截都会被执行，请注意对性能的影响。

也就是说我们进行服务远程调用前，拦截器会对此调用进行拦截处理，那么就好办了，在消费者调用远程服务之前，我们可以偷偷把 ThreadLocal 的内容放进 RpcContext 容器中，我们可以基于 dubbo 的 spi 机制扩展两个拦截器，一个在消费者端生效，另一个在提供者端生效：

在 META-INF 中加入 com.alibaba.dubbo.rpc.Filter 文件，内容如下：

provider=com.objcoding.dubbo.filter.ProviderFilter
consumer=com.objcoding.dubbo.filter.ConsumerFilter

消费者端拦截处理：


public class ConsumerFilter implements Filter {
    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) 
        throws RpcException {

        //1. 从 ThreadLocal 获取请求信息
        Request request = Context.getCurrentRequest();
        //2. 将 Context 参数放到 RpcContext
        RpcContext rpcCTX = RpcContext.getContext();
        // 将初始化的请求信息放进 ThreadLocal 中
        Context.initialLocal(request);

        // ...

    }   
}

Context.getCurrentRequest();就是从 ThreadLocal 中拿到 Request 请求内容，contextToDubboContext(request);将 Request 内容放进当前线程的 RpcContext 容器中。

很容易联想到提供者也就是把 RpcContext 中的内容拿出来放到 ThreadLocal 中：

public class ProviderFilter extends AbstractDubboFilter implements Filter{
     @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) 
        throws RpcException {
        // 1. 获取 RPC 远程调用上下文
        RpcContext rpcCTX = RpcContext.getContext();
        // 2. 初始化请求信息
        Request request = dubboContextToContext(rpcCTX);
        // 3. 将初始化的请求信息放进 ThreadLocal 中
        Context.initialLocal(request);

        // ...

    }   
}

接下来我们还要配置 log4j2，使得我们同一条请求在关联的每一个容器打印的消息，都有一个共同的 traceId，那么我们在 ELK 想要查询某个请求时，只需要搜索 traceId，就可以看到整条请求链路的日志了。

我们在 Context 上下文对象的 initialLocal(Request request) 方法中在 log4j2 的上下文中添加 traceId 信息：

public class Context {
    
    // ...

    final public static String TRACEID = "_traceid";

    public final static void initialLocal(Request request) {if (null == request) {return;}
        // 在 log4j2 的上下文中添加 traceId
        ThreadContext.put(TRACEID, request.getTraceId());
        REQUEST_LOCAL.set(request);
    }
    
    // ...
}

接下来实现org.apache.logging.log4j.core.appender.rewrite.RewritePolicy：

@Plugin(name = "Rewrite", category = "Core", elementType = "rewritePolicy", printObject = true)
public final class MyRewritePolicy implements RewritePolicy {

    // ...
    
    @Override
    public LogEvent rewrite(final LogEvent source) {HashMap<String, String> contextMap = Maps.newHashMap(source.getContextMap());
        contextMap.put(Context.TRACEID, contextMap.containsKey(Context.TRACEID) ? contextMap.get(Context.TRACEID) : NULL);
        return new Log4jLogEvent.Builder(source).setContextMap(contextMap).build();}
    
    // ...
}

RewritePolicy 的作用是我们每次输出日志，log4j 都会调用这个类进行一些处理的操作。

配置 log4j2.xml：

<Configuration status="warn">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout
                pattern="[%d{yyyy/MM/dd HH:mm:ss,SSS}][${ctx:_traceid}]%m%n" />
        </Console>
        
        <!-- 定义一个 Rewrite-->
        <Rewrite name="Rewrite">
            <MyRewritePolicy/>
            <!-- 引用输出模板 -->
            <AppenderRef ref="Console"/>
        </Rewrite>
    </Appenders>
    <Loggers>
       
        <!-- 使用日志模板 -->
        <Logger name="com.objcoding.MyLogger" level="debug" additivity="false">
            <!-- 引用 Rewrite-->
            <AppenderRef ref="Rewrite"/>
        </Logger>
    </Loggers>
</Configuration>

自定义日志类：

public class MyLogger {private static final Logger logger = LoggerFactory.getLogger(MyLogger.class);
    
     public static void info(String msg, Object... args) {if (canLog() == 1 && logger.isInfoEnabled()) {logger.info(msg, args);
        }
    }
    
    public static void debug(String message, Object... args) {if (canLog() == 1 && logger.isDebugEnabled()) {logger.debug(message, args);
        }
    }
    
    // ..
}

更多精彩文章请关注作者维护的公众号「后端进阶」，这是一个专注后端相关技术的公众号。
关注公众号并回复「后端」免费领取后端相关电子书籍。
欢迎分享，转载请保留出处。

Just My Socks（注册教程 内含优惠码）

Just My Socks（注册教程内含优惠码）