文档章节

利用Slf4j的MDC跟踪方法调用链

杨春炼
 杨春炼
发布于 08/18 13:27
字数 1481
阅读 624
收藏 22

why?

一个web项目通常提供很多URL访问地址,

项目一般都是分层处理,例如Controller——>Service——>DAO。

如果想根据日志查看用户一次请求都走了哪些方法(多数是查错误)。

如果系统是多人访问,日志打印是无序的,想要串行拿到日志是大海捞针。

能通过一个字符串就能将一次请求调用了哪些方法按照顺序搜索出来就好了。

how?

Slf4j的MDC ( Mapped Diagnostic Contexts )专门为此需求而生。

MDC的基本原理是:

通过一个ThreadLocal保存设置的key值,在打印的时候从ThreadLocal中获取到打印出来。由此可知,如果一个请求中的某些方法调用是在另外的线程中执行,那MDC是获取不到该值的。

note 当前线程的子线程会继承其父线程中的MDC的内容,所以不用担心会话过程中,新创建的子线程无法追踪。

为什么最开始子线程会得到父线程MDC设置的内容?

创建子线程的时候会调用init(ThreadGroup g, Runnable target, String name,long stackSize)方法,判断如果parent.inheritableThreadLocals不为null就调用createInheritedMap方法把父线程的ThreadLocal里保存的变量都加载到子线程的ThreadLocal中去。

所以MDC类的静态变量mdcAdapter(LogbackMDCAdapter实现)中的copyOnInheritThreadLocal会得到父类MDC写入的内容,因为它用的是InheritableThreadLocal这个继承类。

底层代码

/**
 * This class hides and serves as a substitute for the underlying logging
 * system's MDC implementation.
 * 
 * <p>
 * If the underlying logging system offers MDC functionality, then SLF4J's MDC,
 * i.e. this class, will delegate to the underlying system's MDC. Note that at
 * this time, only two logging systems, namely log4j and logback, offer MDC
 * functionality. For java.util.logging which does not support MDC,
 * {@link BasicMDCAdapter} will be used. For other systems, i.e. slf4j-simple
 * and slf4j-nop, {@link NOPMDCAdapter} will be used.
 *
 * <p>
 * Thus, as a SLF4J user, you can take advantage of MDC in the presence of log4j,
 * logback, or java.util.logging, but without forcing these systems as
 * dependencies upon your users.
 * 
 * <p>
 * For more information on MDC please see the <a
 * href="http://logback.qos.ch/manual/mdc.html">chapter on MDC</a> in the
 * logback manual.
 * 
 * <p>
 * Please note that all methods in this class are static.
 * 
 * @author Ceki G&uuml;lc&uuml;
 * @since 1.4.1
 */
public class MDC {

/**
 * Basic MDC implementation, which can be used with logging systems that lack
 * out-of-the-box MDC support.
 *
 * This code was initially inspired by  logback's LogbackMDCAdapter. However,
 * LogbackMDCAdapter has evolved and is now considerably more sophisticated.
 *
 * @author Ceki Gulcu
 * @author Maarten Bosteels
 * @author Lukasz Cwik
 * 
 * @since 1.5.0
 */
public class BasicMDCAdapter implements MDCAdapter {

    private InheritableThreadLocal<Map<String, String>> inheritableThreadLocal = new InheritableThreadLocal<Map<String, String>>() {
        @Override
        protected Map<String, String> childValue(Map<String, String> parentValue) {
            if (parentValue == null) {
                return null;
            }
            return new HashMap<String, String>(parentValue);
        }
    };

    /**
     * Put a context value (the <code>val</code> parameter) as identified with
     * the <code>key</code> parameter into the current thread's context map.
     * Note that contrary to log4j, the <code>val</code> parameter can be null.
     *
     * <p>
     * If the current thread does not have a context map it is created as a side
     * effect of this call.
     *
     * @throws IllegalArgumentException
     *                 in case the "key" parameter is null
     */
    public void put(String key, String val) {
        if (key == null) {
            throw new IllegalArgumentException("key cannot be null");
        }
        Map<String, String> map = inheritableThreadLocal.get();
        if (map == null) {
            map = new HashMap<String, String>();
            inheritableThreadLocal.set(map);
        }
        map.put(key, val);
    }
/**
 * This class extends <tt>ThreadLocal</tt> to provide inheritance of values
 * from parent thread to child thread: when a child thread is created, the
 * child receives initial values for all inheritable thread-local variables
 * for which the parent has values.  Normally the child's values will be
 * identical to the parent's; however, the child's value can be made an
 * arbitrary function of the parent's by overriding the <tt>childValue</tt>
 * method in this class.
 *
 * <p>Inheritable thread-local variables are used in preference to
 * ordinary thread-local variables when the per-thread-attribute being
 * maintained in the variable (e.g., User ID, Transaction ID) must be
 * automatically transmitted to any child threads that are created.
 *
 * @author  Josh Bloch and Doug Lea
 * @see     ThreadLocal
 * @since   1.2
 */

public class InheritableThreadLocal<T> extends ThreadLocal<T> {
    /**
     * Computes the child's initial value for this inheritable thread-local
     * variable as a function of the parent's value at the time the child
     * thread is created.  This method is called from within the parent
     * thread before the child is started.
     * <p>
     * This method merely returns its input argument, and should be overridden
     * if a different behavior is desired.
     *
     * @param parentValue the parent thread's value
     * @return the child thread's initial value
     */
    protected T childValue(T parentValue) {
        return parentValue;
    }

1 修改日志文件

只需要在日志配置文件的pattern中中添加一个{key},在请求方法入口设置一个key=某字符串,logger日志就能输出此字符串。logger的所有日志方法不需要做任何改动。如下所示。

<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <pattern>%d{ISO8601} [%thread] [%-5level] [%-10X{tracing_id}] %logger - %msg%n</pattern>
    </layout>
  </appender>
  <!-- 文件输出日志 (文件大小策略进行文件输出,超过指定大小对文件备份)-->
  <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>/data/rec_loader/logs/rec_loader.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <fileNamePattern>/data/rec_loader/logs/rec_loader.log.%d{yyyy-MM-dd}.%d{hh-mm-ss}
      </fileNamePattern>
      <maxHistory>7</maxHistory>
      <totalSizeCap>100GB</totalSizeCap>
    </rollingPolicy>
    <layout class="ch.qos.logback.classic.PatternLayout">
	  <!--** 改动在此处 tracing_id**-->
      <Pattern>%d{ISO8601} [%thread] [%-5level] [%-10X{tracing_id}] %logger - %msg%n</Pattern>
    </layout>
  </appender>

  <root level="info">
    <appender-ref ref="STDOUT"/>
    <appender-ref ref="FILE"/>
  </root>

</configuration>

2 增加拦截器(跨系统之间可用,通过增加header字段)

import java.util.Objects;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang3.RandomStringUtils;
import org.apache.commons.lang3.StringUtils;
import org.slf4j.MDC;
import org.springframework.web.servlet.handler.HandlerInterceptorAdapter;

/* *
 * *    Starry Starry Night
 * *          __   __
 * *          \/---\/
 * *           ). .(
 * *          ( (") )
 * *           )   (
 * *          /     \
 * *         (       )``
 * *        ( \ /-\ / )
 * *         w'W   W'w
 * *
 * author   杨春炼
 * email    qdcccc@gmail.com
 * date     2018-08-18
 *
 */
@Slf4j
public class ResponseMetricsInterceptor extends HandlerInterceptorAdapter {
	private static final String TRACING_ID = "tracing_id";
	private static final String RESPONSE_TIME = "response_time";

	@Override
	public boolean preHandle(HttpServletRequest request, HttpServletResponse response,
			Object handler) throws Exception {
		String tracingId;
		//this judgement used for webs context
		if (StringUtils.isBlank(request.getHeader(TRACING_ID))) {
			tracingId = RandomStringUtils.randomAlphanumeric(10);
		} else {
			tracingId = request.getHeader(TRACING_ID);
		}
		response.setHeader(TRACING_ID, tracingId);
		//add a start time in request attribute
		request.setAttribute(RESPONSE_TIME, System.currentTimeMillis());
		MDC.put(TRACING_ID, tracingId);
		log.info("tracing.start.url={}", request.getServletPath());
		return super.preHandle(request, response, handler);
	}

	@Override
	public void afterCompletion(HttpServletRequest request, HttpServletResponse response,
			Object handler, Exception ex) throws Exception {
		try {
			Object attribute = request.getAttribute(RESPONSE_TIME);
			Long timeStart = Long.valueOf(Objects.toString(attribute, "0"));
			long responseTime = System.currentTimeMillis() - timeStart;
			log.info("tracing.end.url={}, 消耗时间:{}ms", request.getServletPath(), responseTime);
		} catch (Exception ignored) {
		} finally {
			//prevent memory leak
			MDC.remove(TRACING_ID);
			MDC.clear();
		}
		super.afterCompletion(request, response, handler, ex);
	}
import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurationSupport;

/* *
 * *    Starry Starry Night
 * *          __   __
 * *          \/---\/
 * *           ). .(
 * *          ( (") )
 * *           )   (
 * *          /     \
 * *         (       )``
 * *        ( \ /-\ / )
 * *         w'W   W'w
 * *
 * author   杨春炼
 * email    qdcccc@gmail.com
 * date     2018-08-18
 *
 */
@Configuration
public class InterceptorConfig extends WebMvcConfigurationSupport {
	@Override
	public void addInterceptors(InterceptorRegistry registry) {
		registry.addInterceptor(new ResponseMetricsInterceptor()).addPathPatterns("/**");
	}
}

Effect

向自己的项目发起一次http请求

结果如下图(顺便打印了该次http请求的总耗时)

更专业的分布式链路追踪中间件?

可以自行搜索 SOFATracer,比较重,觉得一般企业没必要应用。

© 著作权归作者所有

共有 人打赏支持
杨春炼
粉丝 11
博文 61
码字总数 33964
作品 0
海淀
高级程序员
私信 提问
分布式链路追踪中间件 - SOFATracer

SOFATracer 是一个用于分布式系统调用跟踪的组件,通过统一的 将调用链路中的各种网络调用情况以日志的方式记录下来,以达到透视化网络调用的目的。这些日志可用于故障的快速发现,服务治理等...

匿名
05/31
0
0
比较 SLF4J 与 log4j

SLF4J :JAVA简易日志门面(Simple Logging Facade for Java,缩写SLF4J) 他是一套包装Logging 框架的接口程式,以外观模式实现。可在软件部署的时候决定要使用的 Logging 框架,目前主要支援...

Candy_Desire
2014/03/19
0
0
java日志组件介绍(common-logging,log4j,slf4j,logback)

common-logging common-logging是apache提供的一个通用的日志接口。用户可以自由选择第三方的日志组件作为具体实现,像log4j,或者jdk自带的logging, common-logging会通过动态查找的机制,...

五大三粗
2015/11/04
0
0
java日志组件介绍(common-logging,log4j,slf4j,logback )

common-logging是apache提供的一个通用的日志接口。用户可以自由选择第三方的日志组件作为具体实现,像log4j,或者jdk自带的logging, common-logging会通过动态查找的机制,在程序运行时自动...

凯文加内特
2015/05/08
0
0
让 Spring Framework 依赖 SLF4J 的 Maven 配置

Spring Framework 一直以来都是依赖 commons-logging,通过在 Maven pom.xml 进行配置,可以让 Spring Framework 依赖于越来越流行的 SLF4J,这是利用了 slf4j.org 提供的 jcl-over-slf4j 把...

张前程
2013/12/30
0
0

没有更多内容

加载失败,请刷新页面

加载更多

小论Java泛型机制

何为泛型(Generics) 面向对象编程语言的多态特性包括:任一多态(ad hoc polymorphism,又名重载)、子类型多态(subtype polymorphism,又名覆盖)以及参数多态(parameter polymorphism,...

SamYjy
12分钟前
0
0
通过JS+DIV+CSS排版布局实现选项卡效果

CSS介绍及布局特定 层叠样式表是一种用来表现HTML(标准通用标记语言的一个应用)或XML(标准通用标记语言的一个子集)等文件样式的计算机语言。   CSS目前最新版本为CSS3,是能够真正做到...

青衣霓裳
12分钟前
1
0
看图了解RocksDB

它是一个高性能的Key-Value数据库。设计了完善的持久化机制,同时保证性能和安全性。能够良好的支持范围查询,因为K-V记录就是按照Key来排序的。 下图为写入的流程: 可以看到主要的三个组成...

许此一生
19分钟前
2
0
重磅发布!阿里云推PostgreSQL 10 高可用版

2015年,阿里云宣布正式推出RDS for PostgreSQL服务,届时,阿里云成为国内首家同时支持MySQL、SQL Server 和PostgreSQL关系型数据库的云计算服务商。 用户在云上就能享受PostgreSQL引擎带来的...

迷你芊宝宝
19分钟前
0
0
Mysql show Status参数详解

状态名 作用域 详细解释 Aborted_clients Global 由于客户端没有正确关闭连接导致客户端终止而中断的连接数 Aborted_connects Global 试图连接到MySQL服务器而失败的连接数 Binlog_cache_dis...

若杰
25分钟前
0
0

没有更多内容

加载失败,请刷新页面

加载更多

返回顶部
顶部