调用链traceID的简单使用

最新推荐文章于 2024-05-24 14:12:16 发布

FKJGFK

最新推荐文章于 2024-05-24 14:12:16 发布

阅读量2.4k

点赞数

分类专栏：主流框架

本文链接：https://blog.csdn.net/FKJGFK/article/details/108475005

版权

主流框架专栏收录该内容

5 篇文章 1 订阅

订阅专栏

日志输出是定位线上问题的重要手段。但是服务大量并发的情况下，我们很难获取单次请求的完整上下文调用链。可能有同学会想到 tomcat线程名、线程号，但是tomcat线程池能够复用线程。还可能有同学想到程序入口生成一个UUID传递给上下文使用，这种类方式能够解决准确获取调用链，但是当我们代码逻辑较为复杂时，难么这种方式代码侵入性就比较高、历史代码改动也比较大。那么如何精确、优雅的获取调用链呢?

对于logback日志框架比较熟悉的同学就会知道，logback中有一个 MDC (Mapped Diagnostic Context)类，可以自定义参数存放到里面，并在logback.xml输出格式中输出自定义参数变量。

下面我们将简单介绍logback集成方式、MDC的源码分析、异步子线程traceID的传递。

logback集成方式：

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>

<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level %thread [%mdc{MSGID}] %X{traceId} %logger{50} %file:%method:%line - %msg%n</pattern>
</encoder>
</appender>

（一）基于Filter、HandlerInterceptor过滤器方式

import org.apache.log4j.Logger;
import org.springframework.web.servlet.HandlerInterceptor;
import org.springframework.web.servlet.ModelAndView;

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

/**
* 日志拦截器
*/
public class LoggerInterceptor implements HandlerInterceptor {
private static Logger logger=Logger.getLogger(LoggerInterceptor.class);

@Override
public boolean preHandle(HttpServletRequest httpServletRequest, HttpServletResponse httpServletResponse, Object o) throws Exception {
LoggerTools.logger();
return true;
}

@Override
public void postHandle(HttpServletRequest httpServletRequest, HttpServletResponse httpServletResponse, Object o, ModelAndView modelAndView) throws Exception {

}

@Override
public void afterCompletion(HttpServletRequest httpServletRequest, HttpServletResponse httpServletResponse, Object o, Exception e) throws Exception {
LoggerTools.remove();
}
}

import com.demo.test.util.UUIDUtils;
import org.slf4j.MDC;

/**
* 日志工具类
*/
public class LoggerTools {

/**
* 生成本次的序列号
*/
public static void logger() {
MDC.put("traceId",UUIDUtils.getUUID());
}

public static String get() {
return MDC.get("traceId");
}

/**
* 删除本次请求的序列号
*/
public static void remove() {
MDC.remove("traceId");
}
}

<mvc:interceptors>
<mvc:interceptor>
<mvc:mapping path="/demo/**" />
<bean class="com.test.demo.intercept.LoggerInterceptor"/>
</mvc:interceptor>
</mvc:interceptors>

添加之前：
2020-09-08 16:45:37.346 DEBUG http-bio-8090-exec-1 [] com.test.demo.AppController - 终端请求参数:
2020-09-08 16:45:37.368 DEBUG http-bio-8090-exec-1 [] com.test.demo.AppController - 终端请求app票据信息:
2020-09-08 16:45:37.369 DEBUG http-bio-8090-exec-1 [] com.test.demo.AppController - 应用认证、资源认证......

添加之后：
2020-09-08 16:47:51.594 DEBUG http-bio-8090-exec-1 [] com.test.demo.AppController 52e08b643f6c4be8917d51afdde471c6 - 终端请求参数:
2020-09-08 16:47:51.615 DEBUG http-bio-8090-exec-1 [] com.test.demo.AppController 52e08b643f6c4be8917d51afdde471c6 - 终端请求app票据信息:
2020-09-08 16:47:51.615 DEBUG http-bio-8090-exec-1 [] com.test.demo.AppController 52e08b643f6c4be8917d51afdde471c6 - 应用认证、资源认证......

（二）基于Spring AOP切面方式

import java.lang.annotation.*;

@Documented
@Target(value= ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
@Inherited
public @interface TraceID {

}

import com.demo.test.util.UUIDUtils;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;

@Aspect
@Component
public class TraceIDAscept {

public static Logger logger = LoggerFactory.getLogger(TraceIDAscept.class);

@Pointcut("@annotation(com.demo.annon.TraceID)")
public void aspect() {
}

//针对带有注解 @TraceIDd 的方法
@Around(value = "aspect()")
public Object process(ProceedingJoinPoint joinPoint) {
try {
MDC.put("traceId",UUIDUtils.getUUID());
Object obj = joinPoint.proceed();
return obj;
} catch (Throwable e) {
logger.error("traceID添加异常 ", e);
throw new RuntimeException("traceID添加异常");
} finally {
MDC.clear();
}
}

}

@TraceID
@RequestMapping("/demo/test")
@ResponseBody
...

添加之后：
2020-09-08 17:01:17.634 DEBUG http-bio-8090-exec-1 [] com.test.demo.AppController 520f60db915e4ee5b31521886191530b - 终端请求参数:
2020-09-08 17:01:17.660 DEBUG http-bio-8090-exec-1 [] com.test.demo.AppController 520f60db915e4ee5b31521886191530b - 终端请求app票据信息:
2020-09-08 17:01:17.661 DEBUG http-bio-8090-exec-1 [] com.test.demo.AppController 520f60db915e4ee5b31521886191530b - 应用认证、资源认证......

（三）MDC的简单原理

上面介绍完traceId的集成和使用后，我们深入MDC源码一探究竟：

/**
* Copyright (c) 2004-2011 QOS.ch
* All rights reserved.
*
* Permission is hereby granted, free of charge, to any person obtaining
* a copy of this software and associated documentation files (the
* "Software"), to deal in the Software without restriction, including
* without limitation the rights to use, copy, modify, merge, publish,
* distribute, sublicense, and/or sell copies of the Software, and to
* permit persons to whom the Software is furnished to do so, subject to
* the following conditions:
*
* The above copyright notice and this permission notice shall be
* included in all copies or substantial portions of the Software.
*
* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
* EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
* MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
* NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE
* LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION
* OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION
* WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
*
*/
package org.slf4j;

import java.util.Map;

import org.slf4j.helpers.NOPMDCAdapter;
import org.slf4j.helpers.BasicMDCAdapter;
import org.slf4j.helpers.Util;
import org.slf4j.impl.StaticMDCBinder;
import org.slf4j.spi.MDCAdapter;

/**
* This class hides and serves as a substitute for the underlying logging
* system's MDC implementation.
*
* 
* 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.
*
* 
* 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.
*
* 
* 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.
*
* 
* Please note that all methods in this class are static.
*
* @author Ceki Gülcü
* @since 1.4.1
*/
public class MDC {

static final String NULL_MDCA_URL = "http://www.slf4j.org/codes.html#null_MDCA";
static final String NO_STATIC_MDC_BINDER_URL = "http://www.slf4j.org/codes.html#no_static_mdc_binder";
static MDCAdapter mdcAdapter;

private MDC() {
}

static {
try {
mdcAdapter = StaticMDCBinder.SINGLETON.getMDCA();
} catch (NoClassDefFoundError ncde) {
mdcAdapter = new NOPMDCAdapter();
String msg = ncde.getMessage();
if (msg != null && msg.indexOf("StaticMDCBinder") != -1) {
Util.report("Failed to load class \"org.slf4j.impl.StaticMDCBinder\".");
Util.report("Defaulting to no-operation MDCAdapter implementation.");
Util
.report("See " + NO_STATIC_MDC_BINDER_URL + " for further details.");
} else {
throw ncde;
}
} catch (Exception e) {
// we should never get here
Util.report("MDC binding unsuccessful.", e);
}
}

/**
* Put a diagnostic context value (the <code>val</code> parameter) as identified with the
* <code>key</code> parameter into the current thread's diagnostic context map. The
* <code>key</code> parameter cannot be null. The <code>val</code> parameter
* can be null only if the underlying implementation supports it.
*
* 
* This method delegates all work to the MDC of the underlying logging system.
*
* @param key non-null key
* @param val value to put in the map
*
* @throws IllegalArgumentException
* in case the "key" parameter is null
*/
public static void put(String key, String val)
throws IllegalArgumentException {
if (key == null) {
throw new IllegalArgumentException("key parameter cannot be null");
}
if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also "
+ NULL_MDCA_URL);
}
mdcAdapter.put(key, val);
}

/**
* Get the diagnostic context identified by the <code>key</code> parameter. The
* <code>key</code> parameter cannot be null.
*
* 
* This method delegates all work to the MDC of the underlying logging system.
*
* @param key
* @return the string value identified by the <code>key</code> parameter.
* @throws IllegalArgumentException
* in case the "key" parameter is null
*/
public static String get(String key) throws IllegalArgumentException {
if (key == null) {
throw new IllegalArgumentException("key parameter cannot be null");
}

if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also "
+ NULL_MDCA_URL);
}
return mdcAdapter.get(key);
}

/**
* Remove the diagnostic context identified by the <code>key</code> parameter using
* the underlying system's MDC implementation. The <code>key</code> parameter
* cannot be null. This method does nothing if there is no previous value
* associated with <code>key</code>.
*
* @param key
* @throws IllegalArgumentException
* in case the "key" parameter is null
*/
public static void remove(String key) throws IllegalArgumentException {
if (key == null) {
throw new IllegalArgumentException("key parameter cannot be null");
}

if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also "
+ NULL_MDCA_URL);
}
mdcAdapter.remove(key);
}

/**
* Clear all entries in the MDC of the underlying implementation.
*/
public static void clear() {
if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also "
+ NULL_MDCA_URL);
}
mdcAdapter.clear();
}

/**
* Return a copy of the current thread's context map, with keys and values of
* type String. Returned value may be null.
*
* @return A copy of the current thread's context map. May be null.
* @since 1.5.1
*/
public static Map<String, String> getCopyOfContextMap() {
if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also "
+ NULL_MDCA_URL);
}
return mdcAdapter.getCopyOfContextMap();
}

/**
* Set the current thread's context map by first clearing any existing map and
* then copying the map passed as parameter. The context map passed as
* parameter must only contain keys and values of type String.
*
* @param contextMap
* must contain only keys and values of type String
* @since 1.5.1
*/
public static void setContextMap(Map<String, String> contextMap) {
if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also "
+ NULL_MDCA_URL);
}
mdcAdapter.setContextMap(contextMap);
}

/**
* Returns the MDCAdapter instance currently in use.
*
* @return the MDcAdapter instance currently in use.
* @since 1.4.2
*/
public static MDCAdapter getMDCAdapter() {
return mdcAdapter;
}

}

/**
* Logback: the reliable, generic, fast and flexible logging framework.
* Copyright (C) 1999-2015, QOS.ch. All rights reserved.
*
* This program and the accompanying materials are dual-licensed under
* either the terms of the Eclipse Public License v1.0 as published by
* the Eclipse Foundation
*
* or (per the licensee's choosing)
*
* under the terms of the GNU Lesser General Public License version 2.1
* as published by the Free Software Foundation.
*/
package org.slf4j.impl;

import org.slf4j.spi.MDCAdapter;

import ch.qos.logback.classic.util.LogbackMDCAdapter;

/**
* This implementation is bound to {@link LogbackMDCAdapter}.
*
* @author Ceki Gülcü
*/
public class StaticMDCBinder {

/**
* The unique instance of this class.
*/
public static final StaticMDCBinder SINGLETON = new StaticMDCBinder();

private StaticMDCBinder() {
}

/**
* Currently this method always returns an instance of
* {@link StaticMDCBinder}.
*/
public MDCAdapter getMDCA() {
return new LogbackMDCAdapter();
}

public String getMDCAdapterClassStr() {
return LogbackMDCAdapter.class.getName();
}
}

从这个源码中可以看到，MDC的put、get、remove、clear等方法都是基于 MDCAdapter这个类进行操作的，MDCAdapter初始化时通过静态方法块实现了一个 LogbackMDCAdapter子类。我们再看下它的源码:

import java.util.Collections;
import java.util.HashMap;
import java.util.Map;
import java.util.Set;

import org.slf4j.spi.MDCAdapter;

/**
* A Mapped Diagnostic Context, or MDC in short, is an instrument for
* distinguishing interleaved log output from different sources. Log output is
* typically interleaved when a server handles multiple clients
* near-simultaneously.
* 
* The MDC is managed on a per thread basis. A child thread
* automatically inherits a copy of the mapped diagnostic context of
* its parent.
* 
* 
* For more information about MDC, please refer to the online manual at
* http://logback.qos.ch/manual/mdc.html
*
* @author Ceki Gülcü
*/
public class LogbackMDCAdapter implements MDCAdapter {

// The internal map is copied so as

// We wish to avoid unnecessarily copying of the map. To ensure
// efficient/timely copying, we have a variable keeping track of the last
// operation. A copy is necessary on 'put' or 'remove' but only if the last
// operation was a 'get'. Get operations never necessitate a copy nor
// successive 'put/remove' operations, only a get followed by a 'put/remove'
// requires copying the map.
// See http://jira.qos.ch/browse/LOGBACK-620 for the original discussion.

// We no longer use CopyOnInheritThreadLocal in order to solve LBCLASSIC-183
// Initially the contents of the thread local in parent and child threads
// reference the same map. However, as soon as a thread invokes the put()
// method, the maps diverge as they should.
final ThreadLocal<Map<String, String>> copyOnThreadLocal = new ThreadLocal<Map<String, String>>();

private static final int WRITE_OPERATION = 1;
private static final int MAP_COPY_OPERATION = 2;

// keeps track of the last operation performed
final ThreadLocal<Integer> lastOperation = new ThreadLocal<Integer>();

private Integer getAndSetLastOperation(int op) {
Integer lastOp = lastOperation.get();
lastOperation.set(op);
return lastOp;
}

private boolean wasLastOpReadOrNull(Integer lastOp) {
return lastOp == null || lastOp.intValue() == MAP_COPY_OPERATION;
}

private Map<String, String> duplicateAndInsertNewMap(Map<String, String> oldMap) {
Map<String, String> newMap = Collections.synchronizedMap(new HashMap<String, String>());
if (oldMap != null) {
// we don't want the parent thread modifying oldMap while we are
// iterating over it
synchronized (oldMap) {
newMap.putAll(oldMap);
}
}

copyOnThreadLocal.set(newMap);
return newMap;
}

/**
* 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.
* 
* 
* 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) throws IllegalArgumentException {
if (key == null) {
throw new IllegalArgumentException("key cannot be null");
}

Map<String, String> oldMap = copyOnThreadLocal.get();
Integer lastOp = getAndSetLastOperation(WRITE_OPERATION);

if (wasLastOpReadOrNull(lastOp) || oldMap == null) {
Map<String, String> newMap = duplicateAndInsertNewMap(oldMap);
newMap.put(key, val);
} else {
oldMap.put(key, val);
}
}

/**
* Remove the the context identified by the <code>key</code> parameter.
* 
*/
public void remove(String key) {
if (key == null) {
return;
}
Map<String, String> oldMap = copyOnThreadLocal.get();
if (oldMap == null)
return;

Integer lastOp = getAndSetLastOperation(WRITE_OPERATION);

if (wasLastOpReadOrNull(lastOp)) {
Map<String, String> newMap = duplicateAndInsertNewMap(oldMap);
newMap.remove(key);
} else {
oldMap.remove(key);
}
}

/**
* Clear all entries in the MDC.
*/
public void clear() {
lastOperation.set(WRITE_OPERATION);
copyOnThreadLocal.remove();
}

/**
* Get the context identified by the <code>key</code> parameter.
* 
*/
public String get(String key) {
final Map<String, String> map = copyOnThreadLocal.get();
if ((map != null) && (key != null)) {
return map.get(key);
} else {
return null;
}
}

/**
* Get the current thread's MDC as a map. This method is intended to be used
* internally.
*/
public Map<String, String> getPropertyMap() {
lastOperation.set(MAP_COPY_OPERATION);
return copyOnThreadLocal.get();
}

/**
* Returns the keys in the MDC as a {@link Set}. The returned value can be
* null.
*/
public Set<String> getKeys() {
Map<String, String> map = getPropertyMap();

if (map != null) {
return map.keySet();
} else {
return null;
}
}

/**
* Return a copy of the current thread's context map. Returned value may be
* null.
*/
public Map<String, String> getCopyOfContextMap() {
Map<String, String> hashMap = copyOnThreadLocal.get();
if (hashMap == null) {
return null;
} else {
return new HashMap<String, String>(hashMap);
}
}

public void setContextMap(Map<String, String> contextMap) {
lastOperation.set(WRITE_OPERATION);

Map<String, String> newMap = Collections.synchronizedMap(new HashMap<String, String>());
newMap.putAll(contextMap);

// the newMap replaces the old one for serialisation's sake
copyOnThreadLocal.set(newMap);
}
}

从上面可以看出，所有的操作都是基于ThreadLocal<Map<String, String>> copyOnThreadLocal进行保存数据。ThreadLocal而是一个线程内部的存储类，可以在指定线程内存储数据，数据存储以后，只有指定线程可以得到存储数据。每一个线程读取的变量是对应的互相独立的。通过get和set方法就可以得到当前线程对应的值。这样既可保证一个traceID在整个链路中是惟一的，不会出现并发线程安全问题。

附录：

关于多线程TraceId传递的一种实现方式:

import java.util.Map;
import java.util.concurrent.Callable;
import java.util.concurrent.Future;
import java.util.UUID;

import com.demo.test.intercept.LoggerTools;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;

import com.google.common.base.Strings;
import org.springframework.util.CollectionUtils;

/**
* 自定义的线程池,目的是解决异步线程无法从主线程获取MDC变量的问题
*/
public class MdcThreadPoolTaskExecutor extends ThreadPoolTaskExecutor {
private Logger logger = LoggerFactory.getLogger(MdcThreadPoolTaskExecutor.class);
private final static String LOG_ID = "traceId";

@Override
public <T> Future<T> submit(final Callable<T> task) {
final Map<String, String> context = MDC.getCopyOfContextMap();
return super.submit(new Callable<T>() {
@Override
public T call() throws Exception {
// 将父线程的MDC内容传给子线程
T result;
if (!CollectionUtils.isEmpty(context) && !Strings.isNullOrEmpty(context.get(LOG_ID))) {
MDC.setContextMap(context);
} else {
LoggerTools.logger(); //为空设置新值
}
try {
result = task.call();
} finally {
try {
MDC.clear();
} catch (Exception e2) {
logger.warn("mdc clear exception.", e2);
}
}
return result;
}
});
}
}

即把主线程的ThreadLocal中的Map<String,String>传递给子线程，并设置到子线程的ThreadLocal当中。这样子线程直接也能打印出调用链执行的数据了。

FKJGFK

关注

0
点赞
踩
3

收藏

觉得还不错? 一键收藏
0
评论
调用链traceID的简单使用

日志输出是定位线上问题的重要手段。但是服务大量并发的情况下，我们很难获取单次请求的完整上下文调用链。可能有同学会想到tomcat线程名、线程号，但是tomcat线程池能够复用线程。还可能有同学想到程序入口生成一个UUID传递给上下文使用，这种类方式能够解决准确获取调用链，但是当我们代码逻辑较为复杂时，难么这种方式代码侵入性就比较高、历史代码改动也比较大。那么如何精确、优雅的获取调用链呢? 对于logback日志框架比较熟悉的同学就会知道，logback中有一个 MDC(Map...
复制链接

扫一扫

专栏目录