logback实现分布式系统日志链路追踪

程序员文章站 2022-03-05 08:09:35

...

日志链路追踪的必要性

雷迪森俺的杰特们，日志查询不管在测试环境或是生产环境，都是作为一个开发人员经常要去找、要去看的东西。某个业务出现BUG，那么如何迅速的定位我们所要找的日志及相关的其它日志？事关测试及开发人员定位问题的效率，往往大家都是根据自己打印的日志的关键字去查询日志，但是在并发量大、或业务流程长导致日志不连贯的场景中往往你无法通过一次、两次的日志查询看清整个业务线的日志。甚至只能通过去看实时日志然后重现，才能看清问题。然而生产环境中很多时候哪会给你重现的机会，同时现在分布式微服务大力推行，一旦调用其他服务出了BUG 是不是又要重新去找关键字查日志？
问题来了，为什么这么麻烦大家还不去优化？咱打印日志弄的像京东购物一样，弄个订单号本次请求的所有日志都带上该订单号，后台每一次的响应都带上日志订单号，或者只要抛异常就带上日志订单号返回至前端。然后找日志直接查订单号不就可以了吗？测试人员拿着日志ID 交给开发哪还需要复现？效率提高10倍有没有？完美有了方案咱就去干！

新建过滤器

第一步当然是拦截所有的HTTP请求给每个请求所产生的日志都加上一个唯一标识。

引入maven依赖

<dependency>
	<groupId>org.slf4j</groupId>
	<artifactId>slf4j-api</artifactId>
	<version>1.7.13</version>
	<scope>provided</scope>
</dependency>
<dependency>
	<groupId>ch.qos.logback</groupId>
	<artifactId>logback-classic</artifactId>
	<scope>provided</scope>
	<version>1.1.7</version>
</dependency>

新建过滤器MdcFilter 继承 MDCInsertingServletFilter

Logback自带的ch.qos.logback.classic.helpers.MDCInsertingServletFilter能够将HTTP请求的hostname, request URI, user-agent等信息装入MDC

package com.test.trace.web.filter;

import java.io.IOException;
import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
import org.slf4j.MDC;
import com.alibaba.dubbo.common.utils.StringUtils;
import com.test.trace.support.AbstractMyThreadContext;
import com.test.trace.support.AbstractUUIDShort;
import ch.qos.logback.classic.helpers.MDCInsertingServletFilter;

public class MdcFilter extends MDCInsertingServletFilter {
    private static final String HEARDER_FOR_TRACE_ID = "X-TRACE-ID";
    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
            throws IOException, ServletException {
        if (!(request instanceof HttpServletRequest)) {
            return;
        }
        /**如前端传递了唯一标识ID 拿出来直接用 根据业务这段也可以删除 然后去掉if判断*/
        String traceId =
                ((HttpServletRequest) request).getHeader(HEARDER_FOR_TRACE_ID);
        if (StringUtils.isEmpty(traceId)) {
            traceId = AbstractUUIDShort.generate();
        }
        AbstractMyThreadContext.setTraceId(traceId);
        MDC.put(AbstractMyThreadContext.MDC_TRACE_ID,traceId);
        try {
            //从新调动父类的doFilter方法
            super.doFilter(request, response, chain);
        } finally {
            //资源回收
            MDC.remove(AbstractMyThreadContext.MDC_TRACE_ID);
            AbstractMyThreadContext.removeTraceId();
        }
    }
}

package com.test.trace.web.filter;

import org.springframework.boot.autoconfigure.condition.ConditionalOnClass;
import org.springframework.boot.autoconfigure.condition.ConditionalOnMissingBean;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
@ConditionalOnClass(name = "org.springframework.web.servlet.DispatcherServlet")
public class MdcFilterAutoConfigure {

    @Bean
    @ConditionalOnMissingBean(MdcFilter.class)
    public MdcFilter mdcFilter() {
        return new MdcFilter();
    }
}

spring 注解小课堂开课啦

@Configuration 表示该类为spring配置类
@ConditionalOnClass 判断某个类是否存在于 classpath 中两个一起用就是当classpath 中存在org.springframework.web.servlet.DispatcherServlet 就加载MdcFilterAutoConfigure
@Bean 产生一个Bean，然后交给Spring容器管理。@Configuration与@Bean结合使用。@Configuration可理解为用spring的时候xml里面的<beans>标签，@Bean可理解为用spring的时候xml里面的<bean>标签
@ConditionalOnMissingBean 当指定的Bena不存在时返回true，结合@Bean使用就是如果容器中MdcFilter不存在咱们就产生一个MdcFilter交给spring

日志链路ID生成工具类

package com.test.trace.support;

import java.util.Base64;
import java.util.UUID;

public abstract class AbstractUUIDShort {

    /**生成唯一ID*/
    public static String generate() {
        UUID uuid = UUID.randomUUID();
        return compressedUUID(uuid);
    }

    protected static String compressedUUID(UUID uuid) {
        byte[] byUuid = new byte[16];
        long least = uuid.getLeastSignificantBits();
        long most = uuid.getMostSignificantBits();
        long2bytes(most, byUuid, 0);
        long2bytes(least, byUuid, 8);
        return Base64.getEncoder().encodeToString(byUuid);
    }

    protected static void long2bytes(long value, byte[] bytes, int offset) {
        for (int i = 7; i > -1; i--) {
            bytes[offset++] = (byte) ((value >> 8 * i) & 0xFF);
        }
    }
}

日志链路ID存储、与销毁工具类

主要适用于调用dubbo接口时候取出TraceId且做到保证子线程也能拿到TraceId,其实如果不涉及跨系统的接口调用这个类是没有存在的必要的。

package com.test.trace.support;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import java.util.HashMap;
import java.util.Map;

public abstract class AbstractMyThreadContext {

    private static final Logger log = LoggerFactory.getLogger(AbstractMyThreadContext.class);
    /**
     * logback模板对应的变量
     */
    public final static String MDC_TRACE_ID = "traceId";

    public static final String TRACE_ID = "com.test.trace.MyThreadContext_TRACE_ID_KEY";
    //确保子线程能够继承父线程的数据
    private static final ThreadLocal<Map<Object, Object>> RESOURCES =
            new InheritableThreadLocalMap<Map<Object, Object>>();


    protected AbstractMyThreadContext() {}


    public static Map<Object, Object> getResources() {
        return RESOURCES != null ? new HashMap<Object, Object>(RESOURCES.get()) : null;
    }

    public static void setResources(Map<Object, Object> newResources) {
        if (newResources == null || newResources.isEmpty()) {
            return;
        }
        RESOURCES.get().clear();
        RESOURCES.get().putAll(newResources);
    }


    private static Object getValue(Object key) {
        return RESOURCES.get().get(key);
    }


    public static Object get(Object key) {
        if (log.isTraceEnabled()) {
            log.trace("get() - in thread [{}]",Thread.currentThread().getName());
        }

        Object value = getValue(key);
        if ((value != null) && log.isTraceEnabled()) {
            log.trace("Retrieved value of type [{}]  for key [{}] bound to thread [{}]",
                    value.getClass().getName(), key, Thread.currentThread().getName());
        }
        return value;
    }

    public static void put(Object key, Object value) {
        if (key == null) {
            throw new IllegalArgumentException("key cannot be null");
        }

        if (value == null) {
            remove(key);
            return;
        }

        RESOURCES.get().put(key, value);

        if (log.isTraceEnabled()) {
            log.trace("Bound value of type [{}]  for key [{}]  to thread [{}]",
                    value.getClass().getName(), key, Thread.currentThread().getName());
        }
    }

    public static Object remove(Object key) {
        Object value = RESOURCES.get().remove(key);

        if ((value != null) && log.isTraceEnabled()) {
            log.trace("Retrieved value of type [{}]  for key [{}] from thread [{}]",
                    value.getClass().getName(), key, Thread.currentThread().getName());
        }

        return value;
    }

    public static void remove() {
        RESOURCES.remove();
    }

    //从线程局部变量中获取TraceId
    public static String getTraceId() {
        return (String) get(TRACE_ID);
    }

    //将TraceId摄入线程局部变量中
    public static void setTraceId(String xid) {
        put(TRACE_ID, xid);
    }

    //清除线程局部变量中的TraceId
    public static void removeTraceId() {
        remove(TRACE_ID);
    }

    private static final class InheritableThreadLocalMap<T extends Map<Object, Object>>
            extends InheritableThreadLocal<Map<Object, Object>> {
        @Override
        protected Map<Object, Object> initialValue() {
            return new HashMap<Object, Object>(1 << 4);
        }

        @SuppressWarnings({"unchecked"})
        @Override
        protected Map<Object, Object> childValue(Map<Object, Object> parentValue) {
            if (parentValue != null) {
                return (Map<Object, Object>) ((HashMap<Object, Object>) parentValue).clone();
            } else {
                return null;
            }
        }
    }
}

logback.xml设置日志输出格式

<pattern> 属性配置：(贴出我配置的格式 [%X{traceId}] 这个就是线程ID了)
[%-5level] [%contextName] %d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{req.remoteHost}] [%X{req.requestURI}] [%X{traceId}] %logger - %msg%n

到这里整个日志链路追踪完成了一半，已经可以做到所有HTTP的请求都给加上traceId，但是如果我们调用dubbo接口，MdcFilter 是无法拦截的，所以导致logback中找不到traceId，所以我们需要再加一个com.alibaba.dubbo.rpc.Filter用于守好dubbo的消费者和服务提供者的门，消费者需要交出自己的traceId，服务提供者收到请求将traceId摄入。
详见我的上一篇博客：Dubbo之Filter过滤器（拦截器）的使用
比较懒这里我就不做过多的描述了抱歉。

当你完成这一步之后整个日志链路系统基本就完成了90% 如果你足够努力，同时把EFK弄起来查询日志效率直接一步登天

名词解析 EFK

通过filebeat实时收集 nginx访问日志 ▷ filebeat将收集的日志传输至elasticsearch集群 ▷ 通过kibana展示日志。

但是会思考的同学就会问了，老夫的定时任务执行报错了还不一样日了狗，日志里面的traceId是null的啊。
说白了上面的方法还是只搞定外部发起的请求程序自己的定时任务咋整呢？
这时候面试常出现的问题AOP 浮出水面。
AOP有需要了解的同学可以进传送门：轻松实现aop功能的三种方式

新建拦截器

package com.test.trace.interceptor;

import com.test.trace.support.AbstractMyThreadContext;
import com.test.trace.support.AbstractUUIDShort;
import org.aopalliance.intercept.MethodInterceptor;
import org.aopalliance.intercept.MethodInvocation;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.core.Ordered;
import org.springframework.core.annotation.Order;

/**
 * @description logback全局日志交易id拦截器
 */
@Order(Ordered.HIGHEST_PRECEDENCE)
public class MdcTraceIdMethodInteceptor implements MethodInterceptor {
    protected final Logger log = LoggerFactory.getLogger(this.getClass());

    @Override
    public Object invoke(MethodInvocation invocation) throws Throwable {
        if (MDC.get(AbstractMyThreadContext.MDC_TRACE_ID) != null) {
            return invocation.proceed();
        }
        try {
            String traceId = AbstractUUIDShort.generate();
            AbstractMyThreadContext.setTraceId(traceId);
            MDC.put(AbstractMyThreadContext.MDC_TRACE_ID,traceId);
            return invocation.proceed();
        } catch (Throwable e) {
            log.warn("MdcTraceIdMethodInteceptor error", e.getMessage());
            throw e;
        } finally {
            MDC.remove(AbstractMyThreadContext.MDC_TRACE_ID);
            AbstractMyThreadContext.removeTraceId();
        }
    }
}

package com.test.trace.interceptor;

import org.springframework.aop.Advisor;
import org.springframework.aop.aspectj.AspectJExpressionPointcut;
import org.springframework.aop.support.DefaultPointcutAdvisor;
import org.springframework.beans.factory.annotation.Value;
import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

/**
 * @descriptionlogback全局日志交易id拦截器配置 <br/>
 *  主要针对例如 定时任务 MQ等 非HTTP发起的请求没有traceId 配置需要拦截过滤的地址使用 <br/>
 *  配置demo ：<br/>
 *  log.traceId.pointcutExpression=execution(* com.test.service.rabbitmq..*.*(..)) || execution(* com.test.job..*.*(..))
 */
@Configuration
@ConditionalOnProperty(name = "log.traceId.pointcutExpression")
public class MdcTraceIdConfiguration {
    @Value("${log.traceId.pointcutExpression}")
    private String POINTCUT_EXPRESSION;

    @Bean("MdcTraceIdMethodInteceptor")
    public MdcTraceIdMethodInteceptor mdcTraceIdMethodInteceptor() {
        return new MdcTraceIdMethodInteceptor();
    }

    @Bean("MdcTraceIdAdvisor")
    public Advisor MdcTraceIdAdvisor(MdcTraceIdMethodInteceptor mdcTraceIdMethodInteceptor) {
        AspectJExpressionPointcut cut = new AspectJExpressionPointcut();
        cut.setExpression(POINTCUT_EXPRESSION);
        Advisor advisor = new DefaultPointcutAdvisor(cut, mdcTraceIdMethodInteceptor);
        return advisor;
    }
}

注解小课堂又开课啦：错误日志找不到，多半是太懒，打一顿就好

@ConditionalOnProperty 当可以读取到指定name的配置时为true，如果还配置了value属性，那就要比对配置的值要和指定的value一样才是true。

到这里就彻底完成了将漏网之鱼的路径配置一下，打一个jar包各个项目只需依赖一下。如果需要各自配置 log.traceId.pointcutExpression 就搞定了。

相关标签：工作 - 术 logback slf4j log java

上一篇： Debian配置Networking 和 apt-get 源信息

下一篇： Swap Nodes in Pairs

logback实现分布式系统日志链路追踪

日志链路追踪的必要性

新建过滤器

引入maven依赖

新建过滤器MdcFilter 继承 MDCInsertingServletFilter

日志链路ID生成工具类

日志链路ID存储、与销毁工具类

logback.xml设置日志输出格式

新建拦截器

深圳嘉华学校-分布式链路追踪系统Sleuth和ZipKin实战

logback实现链路追踪

Apache SkyWalking分布式链路追踪系统安装部署

SpringBoot项目中通过MDC和自定义Filter操作traceId实现日志链路追踪

dubbo分布式系统链路追踪_zipkin

Dubbo全链路追踪日志的实现

.NetCore从零开始使用Skywalking分布式链路追踪系统

.NetCore从零开始使用Skywalking分布式链路追踪系统

logback实现分布式系统日志链路追踪

python轨迹追踪、全链路日志追踪trace_id实现