dubbo traceId透传实现日志链路追踪（基于Filter和RpcContext实现）

一、要解决什么问题：

使用elk的过程中发现如下问题：

1.无法准确定位一个请求经过了哪些服务
2.多个请求线程的日志交替打印，不利于查看按时间顺序查看一个请求的日志。

二、期望效果

能够查看一个请求完整的链路日志，不受其它请求日志的干扰。

三、动手实现

消费端需要做什么：

1.新建一个拦截器，拦截所有请求，在调用接口前生成一个链路id（traceId）并放入log4j的MDC和dubbo的RpcContext的attachment，此处拦截器是基于jfinal实现，spring mvc可用其它拦截器或aop方案代替，只要实现生成traceId放入内存即可。

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import org.apache.log4j.MDC;

import com.alibaba.dubbo.rpc.RpcContext;
import com.jfinal.aop.Interceptor;
import com.jfinal.aop.Invocation;
import com.jfinal.handler.Handler;
import com.jfinal.kit.StrKit;
import com.ttxn.frameworks.utils.CommonUtil;

public class TraceHandler extends Handler {

    @Override
    public void handle(String target, HttpServletRequest request, HttpServletResponse response, boolean[] isHandled) {
        String token = request.getParameter("token");
        String userId = StrKit.notBlank(token) ? CommonUtil.getUserId(token) : "VISITOR";
        String uuid = CommonUtil.getUuid();
        String traceId = userId + "-" + uuid;
        RpcContext.getContext().setAttachment("traceId", traceId);
        MDC.put("traceId", traceId);
        next.handle(target, request, response, isHandled);
    }

}

2.修改log4j配置文件，在打印日志的开头加上链路id变量（%X{traceId}），用于log4j打印日志时自动打印MDC中的链路id，此时消费端所有log4j日志都会输出链路id。

# log4j.rootLogger=WARN, stdout, file
log4j.rootLogger=INFO, stdout , file
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%X{traceId}%n%-d{yyyy-MM-dd HH:mm:ss}%n[%p]-[Thread: %t]-[%C.%M()]: %m%n

# Output to the File
log4j.appender.file=org.apache.log4j.DailyRollingFileAppender
log4j.appender.file.DatePattern='_'yyyy-MM-dd'.log'
log4j.appender.file.File=${catalina.base}/logs/ttxn_log.log
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%X{traceId}%n%-d{yyyy-MM-dd HH:mm:ss}%n[%p]-[Thread: %t]-[%C.%M()]: %m%n

配置后的消费端log4j输出效果：

Para: [APP公告]
VISITOR-1e2f6d11ca594ea7af3118567d00f004
2019-07-31 17:37:23
[INFO]-[Thread: DubboServerHandler-192.168.5.15:20884-thread-17]-[com.ttxn.frameworks.annotation.redis.RedisCacheInterceptor.intercept()]: cache not hit key=DATA_CACHE_common.getCfg ,filed=5bm/5pKt55S15Y+w

3.自定义一个dubbo filter，为什么消费端要定义这个filter呢？原因是一个接口可能调用多个服务或调用一个服务多次，这样会涉及到多次rpc调用，而RpcContext 的 attachment只在一次rpc会话有效，所以我们需要在每次rpc调用之前放入一次traceId，才能保证多次rpc调用的服务端都能获取到这个traceId，在业务代码中每rpc一次就setAttachment一次太麻烦，所以我选择放入过滤器，对应用开发人员透明。src/main/resources目录下新建META-INF/dubbo/com.alibaba.dubbo.rpc.Filter文件，文件内容如下。

dubboRpcFilter=com.ttxn.api.filter.TraceFilter

修改consumer.xml文件，应用过滤器

<dubbo:consumer timeout="30000" filter="dubboRpcFilter"/> 
import com.alibaba.dubbo.rpc.Filter;
import com.alibaba.dubbo.rpc.Invocation;
import com.alibaba.dubbo.rpc.Invoker;
import com.alibaba.dubbo.rpc.Result;
import com.alibaba.dubbo.rpc.RpcContext;
import com.alibaba.dubbo.rpc.RpcException;
import com.jfinal.kit.StrKit;
import com.ttxn.frameworks.utils.trace.TraceIdUtil;

public class TraceFilter implements Filter {

    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
        String traceId = RpcContext.getContext().getAttachment("traceId");
        if ( !StrKit.isBlank(traceId) ) {
            // *) 从RpcContext里获取traceId并保存
            TraceIdUtil.setTraceId(traceId);
        } else {
            // *) 交互前重新设置traceId, 避免信息丢失
            traceId = TraceIdUtil.getTraceId();
            RpcContext.getContext().setAttachment("traceId", traceId);
        }
        Result result = invoker.invoke(invocation);
        return result;
    }

}

到这里，消费端的工作就做完了，如果你和我一样是jfinal的架构，还需要做一件事，自定义jfinal的请求日志打印器，如下：

import java.io.IOException;
import java.io.Writer;

import org.slf4j.MDC;

import com.alibaba.dubbo.rpc.RpcContext;
/**
 * jfinal请求日志打印工具，用来获得jfinal action report的日志内容，进行自定义后输出
 * @author Administrator
 *
 */
public class JFinalActionReportWriter extends Writer {

    private static final String LOG_PREFIX = "[START]";

    public void write(String str) throws IOException {
        String traceId = MDC.get("traceId");
        System.out.print(LOG_PREFIX + traceId + str);
    }
    public void write(char[] cbuf, int off, int len) throws IOException {}
    public void flush() throws IOException {}
    public void close() throws IOException {}
}

GlobalConfig中增加如下配置

    public void configConstant(Constants me)
    {
        ActionReporter.setWriter(new JFinalActionReportWriter());
    }

就可以自定义jfinal请求输出日志内容，如下，这部分日志是不受log4j配置影响的，所以我们需要做这一步。

[START]VISITOR-dafe84f6ee2f4d2b907a4c7ef8f8d20c
JFinal action report -------- 2019-07-31 17:37:14 ------------------------------
Url         : GET /app/subject/searchSubjectV3_4
Controller  : com.ttxn.api.controller.app.SubjectRest.(SubjectRest.java:1)
Method      : searchSubjectV3_4
Interceptor : com.ttxn.api.interceptor.APIExceptionInterceptor.(APIExceptionInterceptor.java:1)
              com.ttxn.frameworks.plugins.spring.IocInterceptor.(IocInterceptor.java:1)
              com.ttxn.api.decorator.CoverImgInterceptor.(CoverImgInterceptor.java:1)
Parameter   : query=
生产端需要做什么：

1.和消费端一样需要自定义dubbo拦截器，新增配置文件src\main\resources\META-INF\dubbo\com.alibaba.dubbo.rpc.Filter，文件内容：

dubboContextFilter=com.ttxn.webservice.interceptor.dubbo.ContextFilter

修改provider.xml，对生产者应用此拦截器：

    <!-- 提供方调用过程缺省拦截器，将拦截所有service -->
    <dubbo:provider filter="dubboContextFilter"/>

在自定义拦截器中获取traceId，放入MDC：



package com.ttxn.webservice.interceptor.dubbo;

import java.lang.annotation.Annotation;
import java.sql.SQLException;

import org.apache.log4j.MDC;

import com.alibaba.dubbo.rpc.Filter;
import com.alibaba.dubbo.rpc.Invocation;
import com.alibaba.dubbo.rpc.Invoker;
import com.alibaba.dubbo.rpc.Result;
import com.alibaba.dubbo.rpc.RpcContext;
import com.alibaba.dubbo.rpc.RpcException;
import com.jfinal.kit.StrKit;
import com.jfinal.plugin.activerecord.Db;
import com.jfinal.plugin.activerecord.IAtom;
import com.ttxn.frameworks.annotation.transaction.Transaction;
import com.ttxn.frameworks.utils.trace.TraceIdUtil;

public class ContextFilter implements Filter
{
    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation)
        throws RpcException
    {
        String traceId = RpcContext.getContext().getAttachment("traceId");
        if (StrKit.notBlank(traceId)) {
            MDC.put("traceId", traceId);
        }

        Result result = invoker.invoke(invocation);
        return result;
    }

}

修改log4j文件，输出格式中加上traceId变量（%X{traceId}）：

# log4j.rootLogger=WARN, stdout, file
log4j.rootLogger=INFO, stdout , file
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%X{traceId}%n%-d{yyyy-MM-dd HH:mm:ss}%n[%p]-[Thread: %t]-[%C.%M()]: %m%n

# Output to the File
log4j.appender.file=org.apache.log4j.DailyRollingFileAppender
log4j.appender.file.DatePattern='_'yyyy-MM-dd'.log'
log4j.appender.file.File=${catalina.base}/logs/ttxn_log.log
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%X{traceId}%n%-d{yyyy-MM-dd HH:mm:ss}%n[%p]-[Thread: %t]-[%C.%M()]: %m%n

到此就实现了traceId从消费端到生产端的透传，生产端log4j日志如下：

Para: [快报]
VISITOR-1e2f6d11ca594ea7af3118567d00f004
2019-07-31 17:37:23
[INFO]-[Thread: DubboServerHandler-192.168.5.15:20884-thread-15]-[com.ttxn.frameworks.annotation.redis.RedisCacheInterceptor.intercept()]: cache not hit key=DATA_CACHE_base.newsList ,filed=15

我们就可以从kibana中按照traceId来过滤单次请求的所有日志，达到方便排查bug的效果。

原文地址：https://www.cnblogs.com/powerjiajun/p/11279042.html

时间： 2024-08-04 17:48:15

dubbo traceId透传实现日志链路追踪（基于Filter和RpcContext实现）的相关文章

Dubbo透传traceId/logid的一种思路

前言: 随着dubbo的开源, 以及成为apache顶级项目. dubbo越来越受到国内java developer欢迎, 甚至成为服务化自治的首选方案. 随着微服务的流行, 如何跟踪整个调用链, 成了一个课题. 大家能够达成一致的思路, 在调用中添加traceId/logid信息, 至于如何实现, 各家都有自己的思路. 本文将对比几种方案, 重点讲解利用dubbo的自定义filter的机制, 来实现traceId/logid的透传. 方案一: 这个方案也是最直接的方法, 正如所谓所见即所得,

molten：PHP 应用透明链路追踪工具

本文和大家分享的主要是php中应用透明链路追踪工具molten相关内容,一起来看看吧,希望对大家学习php有所帮助. molten molten是应用透明链路追踪工具. molten追踪php核心调用库运行时信息并且按照zipkin/optracing格式输出信息. molten提供多种sapi, 多种采样类型, 上报追踪状态, 模块控制和多种数据落地 类型等功能. 依赖于molten很容易构建基于php语言的 分布式全链路追踪系统 目前已经运行在生产环境上千台机器上. 目录 安装 以下是你需要

.NET Core----zipkin链路追踪使用

本文主要是说明core怎么使用链路追踪 一.添加nuget包 二.在Startup中添加配置 /// <summary> /// 注册zipkinTrace /// </summary> /// <param name="app"></param> /// <param name="loggerFactory"></param> /// <param name="lifetime

聊聊分布式链路追踪

原文链接:http://lidawn.github.io/2018/12/26/distribute-tracing/ 起因 最近一直在做分布式链路追踪的调研和实践,整理一下其中的知识点. 什么是链路追踪 分布式系统变得日趋复杂,越来越多的组件开始走向分布式化,如微服务.分布式数据库.分布式缓存等,使得后台服务构成了一种复杂的分布式网络.在服务能力提升的同时,复杂的网络结构也使问题定位更加困难.在一个请求在经过诸多服务过程中,出现了某一个调用失败的情况,查询具体的异常由哪一个服务引起的就变得十分

Nginx多级反向代理下的IP透传

透传IP 为何要做透传IP 在使用了CDN做加速站点静态资源加速后,当用户请求的静态资源没能命中,此时CDN会到源站请求内容,那么此时访问源站的IP为CDN节点的IP,不仅如此,可能经我们的WAF防火墙和前端的负载均衡(SLB)后更不容易获取到真实的用户IP信息,我们如果要统计用户的访问IP和地区就变得比较麻烦,因为可能不是真实的IP,必须使用一个什么机制将用户IP传递到最终后端的应用服务器才行. 实验环境 访问流程 主机 IP配置 备注 Chrome 10.0.0.1 Windows浏览器 L

利用SpringBoot+Logback手写一个简单的链路追踪

目录 一.实现原理 二.代码实战 三.测试 最近线上排查问题时候,发现请求太多导致日志错综复杂,没办法把用户在一次或多次请求的日志关联在一起,所以就利用SpringBoot+Logback手写了一个简单的链路追踪,下面详细介绍下. 一.实现原理 Spring Boot默认使用LogBack日志系统,并且已经引入了相关的jar包,所以我们无需任何配置便可以使用LogBack打印日志. MDC(Mapped Diagnostic Context,映射调试上下文)是log4j和logback提供的一种

基于 SkyWalking 实现服务链路追踪

SkyWalking简介 SkyWalking是一个开源的观测平台,用于从服务和云原生等基础设施中收集.分析.聚合以及可视化数据.SkyWalking 提供了一种简便的方式来清晰地观测分布式系统,甚至可以观测横跨不同云的系统.SkyWalking 更像是一种现代的应用程序性能监控(Application Performance Monitoring,即APM)工具,专为云原生,基于容器以及分布式系统而设计 SkyWalking 在逻辑上分为四部分:探针.平台后端.存储和用户界面.其架构图如下:

分布式链路追踪系统预研第二篇

本文为博主原创文章,未经博主允许不得转载. 在上篇随笔后,分布式链路在缓慢推进.一直没什么兴致写,zipkin使用elasticsearch作为数据完全是可行的.但是揉合这两者,就存在两种方案: 第一种,保持zipkin,替换掉存储.即保持zipkin架构,替换掉默认数据存储,改用elasticsearch作为存储.这完全是可行的,但是做出来的也仅仅是一个分布式链路追踪系统.zipkin官方有相应的多数据源的实现源码,有兴趣大家可以自行去git上看. 由于我们想要的不只是分布式链路追踪系统,我们

基于zipkin分布式链路追踪系统预研第一篇

分布式服务追踪系统起源于Google的论文“Dapper, a Large-Scale Distributed Systems Tracing Infrastructure”(译文可参考此处),Twitter的zipkin是基于此论文上线较早的分布式链路追踪系统了,而且由于开源快速被各社区所研究,也诞生了很多的版本. 在这里也是对zipkin进行研究,先贴出Twitter zipkin结构图. 结构比较简单,大概流程为: Trace数据的收集至Scribe(Facebook开源的日志传输通路)或