logback 的mdc官方文档 see: 链接

MDC 简介

在一个分布式系统, 存在很多应用，一个调用链路会很长。为了唯一标记每个请求，我们可以将线程名称，用户id 等一些上下文信息放入 MDC。我们可以通过 grep 从大量日志中找到我们需要定位问题的日志。

slf4j MDC 提供的方法：

  1. package org.slf4j;
  3. public class MDC {
  4.   //Put a context value as identified by key
  5.   //into the current thread's context map.
  6.   public static void put(String key, String val);
  8.   //Get the context identified by the key parameter.
  9.   public static String get(String key);
  11.   //Remove the context identified by the key parameter.
  12.   public static void remove(String key);
  14.   //Clear all entries in the MDC.
  15.   public static void clear();
  16. }

slf4j 不做任何实现，具体实现通过mdcAdapter 调用具体 logback 等日志实现。
分布式系统的请求链路：

image.png

Spring Cloud Sleuth 使用

在基于 springCloud 的微服务架构下，分布式链路追踪，使用 Spring Cloud Sleuth。Spring Cloud Sleuth 就使用了 MDC 设置服务的 traceId。官网介绍：

Spring Cloud Sleuth provides Spring Boot auto-configuration for distributed tracing.

Features

Sleuth configures everything you need to get started. This includes where trace data (spans) are reported to, how many traces to keep (sampling), if remote fields (baggage) are sent, and which libraries are traced. Specifically, Spring Cloud Sleuth…

  • Adds trace and span ids to the Slf4J MDC, so you can extract all the logs from a given trace or span in a log aggregator.
  • Instruments common ingress and egress points from Spring applications (servlet filter, rest template, scheduled actions, message channels, feign client).
  • If spring-cloud-sleuth-zipkin is available then the app will generate and report Zipkin-compatible traces via HTTP. By default it sends them to a Zipkin collector service on localhost (port 9411). Configure the location of the service using spring.zipkin.baseUrl.

在程序中，可以直接给MDC 中设置值，MDC.put(“corpId”, 123),在logback.xml 中通过 %X 配置占位符

  1.     <springProperty name="logging.pattern" source="logging.pattern"
  2.                     defaultValue="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{X-B3-TraceId:-},%X{X-B3-ParentSpanId:-},%X{X-B3-SpanId:-},%X{userId},%X{corpId}] %-5level %logger{10} - %msg%n"/>

工作原理

MDC值的设置

org.springframework.cloud.sleuth.log.Slf4jCurrentTraceContext

  1. package org.springframework.cloud.sleuth.log;
  3. import brave.internal.HexCodec;
  4. import brave.internal.Nullable;
  5. import brave.propagation.CurrentTraceContext;
  6. import brave.propagation.TraceContext;
  7. import org.slf4j.Logger;
  8. import org.slf4j.LoggerFactory;
  9. import org.slf4j.MDC;
  11. /**
  12.  * Adds {@linkplain org.slf4j.MDC} properties "traceId", "parentId", "spanId" and "spanExportable" when a {@link
  13.  * brave.Tracer#currentSpan() span is current}. These can be used in log correlation.
  14.  * Supports backward compatibility of MDC entries by adding legacy "X-B3" entries to MDC context
  15.  * "X-B3-TraceId", "X-B3-ParentSpanId", "X-B3-SpanId" and "X-B3-Sampled"
  16.  *
  17.  * @author Marcin Grzejszczak
  18.  *
  19.  * @since 2.0.0
  20.  */
  21. public final class Slf4jCurrentTraceContext extends CurrentTraceContext {
  23.     // Backward compatibility for all logging patterns
  24.     private static final String LEGACY_EXPORTABLE_NAME = "X-Span-Export";
  25.     private static final String LEGACY_PARENT_ID_NAME = "X-B3-ParentSpanId";
  26.     private static final String LEGACY_TRACE_ID_NAME = "X-B3-TraceId";
  27.     private static final String LEGACY_SPAN_ID_NAME = "X-B3-SpanId";
  29.     private static final Logger log = LoggerFactory
  30.             .getLogger(Slf4jCurrentTraceContext.class);
  32.     public static Slf4jCurrentTraceContext create() {
  33.         return create(CurrentTraceContext.Default.inheritable());
  34.     }
  36.     public static Slf4jCurrentTraceContext create(CurrentTraceContext delegate) {
  37.         return new Slf4jCurrentTraceContext(delegate);
  38.     }
  40.     final CurrentTraceContext delegate;
  42.     Slf4jCurrentTraceContext(CurrentTraceContext delegate) {
  43.         if (delegate == null)
  44.             throw new NullPointerException("delegate == null");
  45.         this.delegate = delegate;
  46.     }
  48.     @Override public TraceContext get() {
  49.         return this.delegate.get();
  50.     }
  52.     @Override public Scope newScope(@Nullable TraceContext currentSpan) {
  53.         final String previousTraceId = MDC.get("traceId");
  54.         final String previousParentId = MDC.get("parentId");
  55.         final String previousSpanId = MDC.get("spanId");
  56.         final String spanExportable = MDC.get("spanExportable");
  57.         final String legacyPreviousTraceId = MDC.get(LEGACY_TRACE_ID_NAME);
  58.         final String legacyPreviousParentId = MDC.get(LEGACY_PARENT_ID_NAME);
  59.         final String legacyPreviousSpanId = MDC.get(LEGACY_SPAN_ID_NAME);
  60.         final String legacySpanExportable = MDC.get(LEGACY_EXPORTABLE_NAME);
  62.         if (currentSpan != null) {
  63.             String traceIdString = currentSpan.traceIdString();
  64.             MDC.put("traceId", traceIdString);
  65.             MDC.put(LEGACY_TRACE_ID_NAME, traceIdString);
  66.             String parentId = currentSpan.parentId() != null ?
  67.                     HexCodec.toLowerHex(currentSpan.parentId()) :
  68.                     null;
  69.             replace("parentId", parentId);
  70.             replace(LEGACY_PARENT_ID_NAME, parentId);
  71.             String spanId = HexCodec.toLowerHex(currentSpan.spanId());
  72.             MDC.put("spanId", spanId);
  73.             MDC.put(LEGACY_SPAN_ID_NAME, spanId);
  74.             String sampled = String.valueOf(currentSpan.sampled());
  75.             MDC.put("spanExportable", sampled);
  76.             MDC.put(LEGACY_EXPORTABLE_NAME, sampled);
  77.             log("Starting scope for span: {}", currentSpan);
  78.             if (currentSpan.parentId() != null) {
  79.                 if (log.isTraceEnabled()) {
  80.                     log.trace("With parent: {}", currentSpan.parentId());
  81.                 }
  82.             }
  83.         }
  84.         else {
  85.             MDC.remove("traceId");
  86.             MDC.remove("parentId");
  87.             MDC.remove("spanId");
  88.             MDC.remove("spanExportable");
  89.             MDC.remove(LEGACY_TRACE_ID_NAME);
  90.             MDC.remove(LEGACY_PARENT_ID_NAME);
  91.             MDC.remove(LEGACY_SPAN_ID_NAME);
  92.             MDC.remove(LEGACY_EXPORTABLE_NAME);
  93.         }
  95.         Scope scope = this.delegate.newScope(currentSpan);
  97.         class ThreadContextCurrentTraceContextScope implements Scope {
  98.             @Override public void close() {
  99.                 log("Closing scope for span: {}", currentSpan);
  100.                 scope.close();
  101.                 replace("traceId", previousTraceId);
  102.                 replace("parentId", previousParentId);
  103.                 replace("spanId", previousSpanId);
  104.                 replace("spanExportable", spanExportable);
  105.                 replace(LEGACY_TRACE_ID_NAME, legacyPreviousTraceId);
  106.                 replace(LEGACY_PARENT_ID_NAME, legacyPreviousParentId);
  107.                 replace(LEGACY_SPAN_ID_NAME, legacyPreviousSpanId);
  108.                 replace(LEGACY_EXPORTABLE_NAME, legacySpanExportable);
  109.             }
  110.         }
  111.         return new ThreadContextCurrentTraceContextScope();
  112.     }
  114.     private void log(String text, TraceContext span) {
  115.         if (span == null) {
  116.             return;
  117.         }
  118.         if (log.isTraceEnabled()) {
  119.             log.trace(text, span);
  120.         }
  121.     }
  123.     static void replace(String key, @Nullable String value) {
  124.         if (value != null) {
  125.             MDC.put(key, value);
  126.         }
  127.         else {
  128.             MDC.remove(key);
  129.         }
  130.     }
  131. }

上面类，会将请求 span 里面的 traceId，spanId，X-B3-TraceId”, “X-B3-ParentSpanId”, “X-B3-SpanId” and “X-B3-Sampled” 设置到 MDC 上下文。

Rest 请求处理

TracingFilter 实现了 servlet 的 filter 接口，在filter 方法中进行了处理

  1. package brave.servlet;
  3. import brave.Span;
  4. import brave.SpanCustomizer;
  5. import brave.Tracer;
  6. import brave.Tracing;
  7. import brave.http.HttpServerHandler;
  8. import brave.http.HttpTracing;
  9. import brave.propagation.CurrentTraceContext;
  10. import brave.propagation.CurrentTraceContext.Scope;
  11. import brave.propagation.Propagation.Getter;
  12. import brave.propagation.TraceContext;
  13. import java.io.IOException;
  14. import javax.servlet.Filter;
  15. import javax.servlet.FilterChain;
  16. import javax.servlet.FilterConfig;
  17. import javax.servlet.ServletException;
  18. import javax.servlet.ServletRequest;
  19. import javax.servlet.ServletResponse;
  20. import javax.servlet.http.HttpServletRequest;
  21. import javax.servlet.http.HttpServletResponse;
  23. public final class TracingFilter implements Filter {
  24.   static final Getter<HttpServletRequest, String> GETTER =
  25.       new Getter<HttpServletRequest, String>() {
  26.         @Override public String get(HttpServletRequest carrier, String key) {
  27.           return carrier.getHeader(key);
  28.         }
  30.         @Override public String toString() {
  31.           return "HttpServletRequest::getHeader";
  32.         }
  33.       };
  34.   static final HttpServletAdapter ADAPTER = new HttpServletAdapter();
  36.   public static Filter create(Tracing tracing) {
  37.     return new TracingFilter(HttpTracing.create(tracing));
  38.   }
  40.   public static Filter create(HttpTracing httpTracing) {
  41.     return new TracingFilter(httpTracing);
  42.   }
  44.   final ServletRuntime servlet = ServletRuntime.get();
  45.   final CurrentTraceContext currentTraceContext;
  46.   final Tracer tracer;
  47.   final HttpServerHandler<HttpServletRequest, HttpServletResponse> handler;
  48.   final TraceContext.Extractor<HttpServletRequest> extractor;
  50.   TracingFilter(HttpTracing httpTracing) {
  51.     tracer = httpTracing.tracing().tracer();
  52.     currentTraceContext = httpTracing.tracing().currentTraceContext();
  53.     handler = HttpServerHandler.create(httpTracing, ADAPTER);
  54.     extractor = httpTracing.tracing().propagation().extractor(GETTER);
  55.   }
  57.   @Override
  58.   public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
  59.       throws IOException, ServletException {
  60.     HttpServletRequest httpRequest = (HttpServletRequest) request;
  61.     HttpServletResponse httpResponse = servlet.httpResponse(response);
  63.     //1.防止同一个请求存在相同的 span
  64.     // Prevent duplicate spans for the same request
  65.     TraceContext context = (TraceContext) request.getAttribute(TraceContext.class.getName());
  66.     if (context != null) {
  67.       // A forwarded request might end up on another thread, so make sure it is scoped
  68.       Scope scope = currentTraceContext.maybeScope(context);
  69.       try {
  70.         chain.doFilter(request, response);
  71.       } finally {
  72.         scope.close();
  73.       }
  74.       return;
  75.     }
  77.     Span span = handler.handleReceive(extractor, httpRequest);
  79.     // Add attributes for explicit access to customization or span context
  80.     request.setAttribute(SpanCustomizer.class.getName(), span.customizer());
  81.     request.setAttribute(TraceContext.class.getName(), span.context());
  83.     Throwable error = null;
  84.     // 调用 Slf4jCurrentTraceContext 维护span
  85.     Scope scope = currentTraceContext.newScope(span.context());
  86.     try {
  87.       // any downstream code can see Tracer.currentSpan() or use Tracer.currentSpanCustomizer()
  88.       chain.doFilter(httpRequest, httpResponse);
  89.     } catch (IOException | ServletException | RuntimeException | Error e) {
  90.       error = e;
  91.       throw e;
  92.     } finally {
  93.       scope.close();
  94.       if (servlet.isAsync(httpRequest)) { // we don't have the actual response, handle later
  95.         servlet.handleAsync(handler, httpRequest, httpResponse, span);
  96.       } else { // we have a synchronous response, so we can finish the span
  97.         handler.handleSend(ADAPTER.adaptResponse(httpRequest, httpResponse), error, span);
  98.       }
  99.     }
  100.   }
  102.   @Override public void destroy() {
  103.   }
  105.   @Override
  106.   public void init(FilterConfig filterConfig) {
  107.   }
  108. }

Async 请求

通过 aop 切面实现，如果有需求对异步的任务进行增强，可以学习参考这块的代码，不需要重复造轮子。。

  1. @Aspect
  2. public class TraceAsyncAspect {
  4.     private static final String CLASS_KEY = "class";
  5.     private static final String METHOD_KEY = "method";
  7.     private final Tracer tracer;
  8.     private final SpanNamer spanNamer;
  10.     public TraceAsyncAspect(Tracer tracer, SpanNamer spanNamer) {
  11.         this.tracer = tracer;
  12.         this.spanNamer = spanNamer;
  13.     }
  15.     @Around("execution (@org.springframework.scheduling.annotation.Async  * *.*(..))")
  16.     public Object traceBackgroundThread(final ProceedingJoinPoint pjp) throws Throwable {
  17.         String spanName = name(pjp);
  18.         Span span = this.tracer.currentSpan();
  19.         if (span == null) {
  20.             span = this.tracer.nextSpan();
  21.         }
  22.         span = span.name(spanName);
  23.         try(Tracer.SpanInScope ws = this.tracer.withSpanInScope(span)) {
  24.             span.tag(CLASS_KEY, pjp.getTarget().getClass().getSimpleName());
  25.             span.tag(METHOD_KEY, pjp.getSignature().getName());
  26.             return pjp.proceed();
  27.         } finally {
  28.             span.finish();
  29.         }
  30.     }
  32.     String name(ProceedingJoinPoint pjp) {
  33.         return this.spanNamer.name(getMethod(pjp, pjp.getTarget()),
  34.                 SpanNameUtil.toLowerHyphen(pjp.getSignature().getName()));
  35.     }
  37.     private Method getMethod(ProceedingJoinPoint pjp, Object object) {
  38.         MethodSignature signature = (MethodSignature) pjp.getSignature();
  39.         Method method = signature.getMethod();
  40.         return ReflectionUtils
  41.                 .findMethod(object.getClass(), method.getName(), method.getParameterTypes());
  42.     }

这里对 runnable 和Callable 进行了装饰增强，在具体任务执行前，进行了请求span 的设置

  1. public class TraceCallable<V> implements Callable<V> {
  3.     /**
  4.      * Since we don't know the exact operation name we provide a default
  5.      * name for the Span
  6.      */
  7.     private static final String DEFAULT_SPAN_NAME = "async";
  9.     private final Tracer tracer;
  10.     private final Callable<V> delegate;
  11.     private final TraceContext parent;
  12.     private final String spanName;
  14.     public TraceCallable(Tracing tracing, SpanNamer spanNamer, Callable<V> delegate) {
  15.         this(tracing, spanNamer, delegate, null);
  16.     }
  18.     public TraceCallable(Tracing tracing, SpanNamer spanNamer, Callable<V> delegate, String name) {
  19.         this.tracer = tracing.tracer();
  20.         this.delegate = delegate;
  21.         this.parent = tracing.currentTraceContext().get();
  22.         this.spanName = name != null ? name : spanNamer.name(delegate, DEFAULT_SPAN_NAME);
  23.     }
  25.     @Override public V call() throws Exception {
  26.         ScopedSpan span = this.tracer.startScopedSpanWithParent(this.spanName, this.parent);
  27.         try {
  28.             return this.delegate.call();
  29.         } catch (Exception | Error e) {
  30.             span.error(e);
  31.             throw e;
  32.         } finally {
  33.             span.finish();
  34.         }
  35.     }
  36. }
  1. public class TraceRunnable implements Runnable {
  3.     /**
  4.      * Since we don't know the exact operation name we provide a default
  5.      * name for the Span
  6.      */
  7.     private static final String DEFAULT_SPAN_NAME = "async";
  9.     private final Tracer tracer;
  10.     private final Runnable delegate;
  11.     private final TraceContext parent;
  12.     private final String spanName;
  14.     public TraceRunnable(Tracing tracing, SpanNamer spanNamer, Runnable delegate) {
  15.         this(tracing, spanNamer, delegate, null);
  16.     }
  18.     public TraceRunnable(Tracing tracing, SpanNamer spanNamer, Runnable delegate, String name) {
  19.         this.tracer = tracing.tracer();
  20.         this.delegate = delegate;
  21.         this.parent = tracing.currentTraceContext().get();
  22.         this.spanName = name != null ? name : spanNamer.name(delegate, DEFAULT_SPAN_NAME);
  23.     }
  25.     @Override
  26.     public void run() {
  27.         ScopedSpan span = this.tracer.startScopedSpanWithParent(this.spanName, this.parent);
  28.         try {
  29.             this.delegate.run();
  30.         } catch (Exception | Error e) {
  31.             span.error(e);
  32.             throw e;
  33.         } finally {
  34.             span.finish();
  35.         }
  36.     }
  37. }

ScheduledExecutorService 和 ExecutorService 也使用了装饰器模式进行增强，任务执行时，传入了增强后的 runnable 和callable 对象。这里可以借鉴，如果需要对线程池执行的任务进行增强，比如在任务的执行前后做一些统计，做一个额外的操作，可以借鉴这种思路。

  1. public class TraceableScheduledExecutorService extends TraceableExecutorService implements ScheduledExecutorService {
  3.     public TraceableScheduledExecutorService(BeanFactory beanFactory, final ExecutorService delegate) {
  4.         super(beanFactory, delegate);
  5.     }
  7.     private ScheduledExecutorService getScheduledExecutorService() {
  8.         return (ScheduledExecutorService) this.delegate;
  9.     }
  11.     @Override
  12.     public ScheduledFuture<?> schedule(Runnable command, long delay, TimeUnit unit) {
  13.         Runnable r = new TraceRunnable(tracing(), spanNamer(), command);
  14.         return getScheduledExecutorService().schedule(r, delay, unit);
  15.     }
  17.     @Override
  18.     public <V> ScheduledFuture<V> schedule(Callable<V> callable, long delay, TimeUnit unit) {
  19.         Callable<V> c = new TraceCallable<>(tracing(), spanNamer(), callable);
  20.         return getScheduledExecutorService().schedule(c, delay, unit);
  21.     }
  23.     @Override
  24.     public ScheduledFuture<?> scheduleAtFixedRate(Runnable command, long initialDelay, long period, TimeUnit unit) {
  25.         Runnable r = new TraceRunnable(tracing(), spanNamer(), command);
  26.         return getScheduledExecutorService().scheduleAtFixedRate(r, initialDelay, period, unit);
  27.     }
  29.     @Override
  30.     public ScheduledFuture<?> scheduleWithFixedDelay(Runnable command, long initialDelay, long delay, TimeUnit unit) {
  31.         Runnable r = new TraceRunnable(tracing(), spanNamer(), command);
  32.         return getScheduledExecutorService().scheduleWithFixedDelay(r, initialDelay, delay, unit);
  33.     }
  35. }

Scheduling 任务

周期任务上下文也是通过切面增强实现

  1. @Aspect
  2. public class TraceSchedulingAspect {
  4.     private static final String CLASS_KEY = "class";
  5.     private static final String METHOD_KEY = "method";
  7.     private final Tracer tracer;
  8.     private final Pattern skipPattern;
  10.     public TraceSchedulingAspect(Tracer tracer, Pattern skipPattern) {
  11.         this.tracer = tracer;
  12.         this.skipPattern = skipPattern;
  13.     }
  15.     @Around("execution (@org.springframework.scheduling.annotation.Scheduled  * *.*(..))")
  16.     public Object traceBackgroundThread(final ProceedingJoinPoint pjp) throws Throwable {
  17.         if (this.skipPattern.matcher(pjp.getTarget().getClass().getName()).matches()) {
  18.             return pjp.proceed();
  19.         }
  20.         String spanName = SpanNameUtil.toLowerHyphen(pjp.getSignature().getName());
  21.         Span span = startOrContinueRenamedSpan(spanName);
  22.         try(Tracer.SpanInScope ws = this.tracer.withSpanInScope(span.start())) {
  23.             span.tag(CLASS_KEY, pjp.getTarget().getClass().getSimpleName());
  24.             span.tag(METHOD_KEY, pjp.getSignature().getName());
  25.             return pjp.proceed();
  26.         } finally {
  27.             span.finish();
  28.         }
  29.     }
  31.     private Span startOrContinueRenamedSpan(String spanName) {
  32.         Span currentSpan = this.tracer.currentSpan();
  33.         if (currentSpan != null) {
  34.             return currentSpan.name(spanName);
  35.         }
  36.         return this.tracer.nextSpan().name(spanName);
  37.     }
  39. }

使用

日志追溯

为了方便排查问题，每个请求的response ,都返回了一个 traceId, traceId 是一个完整链路的唯一标识。通过traceId，去查询日志，直接可以获取当前请求的全链路日志信息。
image.png

在服务器端查询日志，通过traceId可以把整个请求链路串起来

  1. ## 网关日志
  2. [commuser1@lg-h-1-94 log]$ grep 24ee988678463fb3 log.log 
  3. 2021-11-24 09:47:48.593 [reactor-http-epoll-14] [24ee988678463fb3,,24ee988678463fb3,,] INFO  c.e.p.m.g.s.WebsiteGatewayService - request token:a9d72f3a-9ed6-4b80-8fbf-dbb0b0e91d93
  5. ## busi服务日志
  6. [commuser1@lg-h-1-94 log]$ grep 24ee988678463fb3 log.log 
  7. 2021-11-24 09:47:48.602 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.b.s.i.WaybillServiceImpl - @pageQueryByCondition waybillQueryVO:{
  8. 2021-11-24 09:47:48.611 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.l.d.f.s.i.DefaultLevelDataFiltrationRuleKeyServiceImpl - DefaultLevelDataFiltrationRuleKeyServiceImpl.getCurrentUserDataFiltrationRuleKey()方法获取的用户信息=【[{"userType":0,"corpId":193729,"orgId":-85485}]】
  9. 2021-11-24 09:47:48.774 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.l.d.f.s.i.DefaultLevelDataFiltrationRuleKeyServiceImpl - DefaultLevelDataFiltrationRuleKeyServiceImpl.getCurrentUserDataFiltrationRuleKey()方法获取的用户信息=【[{"userType":0,"corpId":193729,"orgId":-85485}]】
  10. 2021-11-24 09:47:48.932 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.f.s.u.ExtendFieldHandleUtil - 获取公司193729表对应扩展字段设置：waybill_info
  11. 2021-11-24 09:47:48.933 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.f.s.u.ExtendFieldHandleUtil - 获取公司对应扩展字段设置结果：{"extendName":[{"extendFieldName":"ext_str7","extendJson":"{}","extendLabel":"集装箱号","extendType":1,"searchType":1},{"extendFieldName":"ext_str3","extendJson":"{}","extendLabel":"起始日期","extendType":3,"searchType":3},{"extendFieldName":"ext_str2","extendJson":"{}","extendLabel":"账单","extendType":2,"searchType":2},{"extendFieldName":"ext_str1","extendJson":"{}","extendLabel":"QQ号","extendType":1,"searchType":1},{"extendFieldName":"ext_str8","extendJson":"{\"cacheKey\":\"BASE_VEHICLE_MAP\"}","extendLabel":"扩展车辆","extendType":7,"searchType":7},{"extendFieldName":"ext_str10","extendJson":"{\"cacheKey\":\"BASE_VEHICLE_MAP\"}","extendLabel":"超超超超","extendType":7,"searchType":7},{"extendFieldName":"ext_str4","extendJson":"{}","extendLabel":"结���日期","extendType":3,"searchType":4},{"extendFieldName":"ext_str9","extendJson":"{\"cacheKey\":\"BASE_CARRIER_MAP\"}","extendLabel":"大胆的加","extendType":5,"searchType":5},{"extendFieldName":"ext_str6","extendJson":"{\"cacheKey\":\"additionalRequirements\"}","extendLabel":"附加要求","extendType":4,"searchType":5}],"primaryKeyName":"id"}
  12. 2021-11-24 09:47:48.934 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.b.s.i.WaybillServiceImpl - @totalCount:22,waybillInfoPOList:20
  13. 2021-11-24 09:47:49.407 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.c.c.s.i.CacheFetchDataRpcServiceImpl - rpc获取缓存：CORP_CAR_MODEL_MAP
  14. 2021-11-24 09:47:49.407 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.c.c.s.i.CacheFetchDataRpcServiceImpl - rpc获取缓存url：http://E6-MS-TMS-BASE-WEB/CORP_CAR_MODEL_MAP?modifyTime
  15. 2021-11-24 09:47:49.514 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.c.c.s.i.CacheServiceRedisImpl - 更新缓存：CORP_CAR_MODEL_MAP193729,大小：72
  16. 2021-11-24 09:47:49.537 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.b.a.i.w.u.a.WaybillUploadReceiptAble - 运单：622678780454305792，转运状态:false
  17. 2021-11-24 09:47:49.543 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.b.a.i.w.u.a.WaybillUploadReceiptAble - 运单：622662423156023296，转运���态:false
  18. 2021-11-24 09:47:49.548 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.b.a.i.w.u.a.WaybillUploadReceiptAble - 运单：622604542533230592，转运状态:false
  19. 2021-11-24 09:47:49.550 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.b.a.i.w.s.a.WaybillShipmentConfirmAble - 运单622604542533230592确认装货操作不允许
  20. 2021-11-24 09:47:49.550 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.b.a.i.w.a.a.WaybillArriveAble - 运单：622604542533230592,不允许到达
  21. 2021-11-24 09:47:49.550 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.b.a.i.w.l.a.WaybillLeaveAble - Not Found Order, waybill: 622604542533230592
  22. 2021-11-24 09:47:49.551 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.b.a.i.w.t.a.WaybillTransferAble - Not Found loadNodeList
  23. 2021-11-24 09:47:49.552 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.t.c.c.e.E6TransformControllerAdviceProcessor - id换name耗时:1
  24. 2021-11-24 09:47:49.565 [http-nio-30030-exec-1] [24ee988678463fb3,24ee988678463fb3,aee8b388cf00d0cf,314117,193729,] INFO  c.e.p.c.w.E6CommonFilter - /waybill/pageQueryByCondition, 请求耗时: 970 ms
  26. ## base 服务日志（busi rpc调用）
  27. [commuser1@2lg-1-25 log]$ grep 24ee988678463fb3 log.log 
  28. 2021-11-24 09:47:49.515 [http-nio-30020-exec-4] [24ee988678463fb3,aee8b388cf00d0cf,9d3971a63dc5950e,,,] DEBUG c.e.p.t.b.b.m.C.corpCarModelMap - ==>  Preparing: SELECT id, `name` label FROM car_model_info WHERE corp_id = ? AND valid = 1
  29. 2021-11-24 09:47:49.515 [http-nio-30020-exec-4] [24ee988678463fb3,aee8b388cf00d0cf,9d3971a63dc5950e,,,] DEBUG c.e.p.t.b.b.m.C.corpCarModelMap - ==> Parameters: 193729(Integer)
  30. 2021-11-24 09:47:49.518 [http-nio-30020-exec-4] [24ee988678463fb3,aee8b388cf00d0cf,9d3971a63dc5950e,,,] DEBUG c.e.p.t.b.b.m.C.corpCarModelMap - <==      Total: 72
  31. 2021-11-24 09:47:49.519 [http-nio-30020-exec-4] [24ee988678463fb3,aee8b388cf00d0cf,9d3971a63dc5950e,,,] INFO  c.e.p.c.w.E6CommonFilter - /CORP_CAR_MODEL_MAP, 请求耗时: 7 ms
  33. ## base 服务日志（busi rpc调用）
  34. [commuser1@lg-h-1-94 log]$ grep 24ee988678463fb3 log.log 
  35. 2021-11-24 09:47:49.115 [http-nio-30020-exec-9] [24ee988678463fb3,aee8b388cf00d0cf,a1b9f8881f547fdf,314117,193729,E6-MS-TMS-BUSI-WEB] DEBUG c.e.p.t.b.b.m.B.findByCorpIdAndIds - ==>  Preparing: SELECT line.remark, line.id, line.NAME, line.car_id, line.driver_id, line.department_id, line.area_name web_sit, line.total_odo, line.corp_id, line.version, line.created_time, line.modified_time, line.created_user_id, line_area.id AS line_id, line_area.fixed_line_id, line_area.custom_area_id, line_area.arrive_time, line_area.leave_time, line_area.day_span_num, line_area.transport_duration, line_area.stay_duration, line_area.corp_id AS area_corp_id, line_area.version AS area_version, line_area.order_index AS order_index, line_area.node_type AS node_type, line_dept.dept_id FROM base_fixed_line_info line LEFT JOIN base_fixed_line_area line_area ON line.id = line_area.fixed_line_id AND line_area.valid = 1 LEFT JOIN base_fixed_line_dept line_dept ON line.id = line_dept.fixed_line_id AND line_dept.valid = 1 WHERE line.valid = 1 AND line.corp_id = ? AND line.id IN (?, ?, ?, ?, ?, ?, ?, ?)
  36. 2021-11-24 09:47:49.115 [http-nio-30020-exec-9] [24ee988678463fb3,aee8b388cf00d0cf,a1b9f8881f547fdf,314117,193729,E6-MS-TMS-BUSI-WEB] DEBUG c.e.p.t.b.b.m.B.findByCorpIdAndIds - ==> Parameters: 193729(Integer), 575919374336458752(String), 617978466980659200(String), 572201287230488576(String), 590758690929573888(String), 564686140972269568(String), 603073434750484480(String), 518591504745955328(String), 607460392757297152(String)
  37. 2021-11-24 09:47:49.396 [http-nio-30020-exec-9] [24ee988678463fb3,aee8b388cf00d0cf,a1b9f8881f547fdf,314117,193729,E6-MS-TMS-BUSI-WEB] DEBUG c.e.p.t.b.b.m.B.findByCorpIdAndIds - <==      Total: 35
  38. 2021-11-24 09:47:49.400 [http-nio-30020-exec-9] [24ee988678463fb3,aee8b388cf00d0cf,a1b9f8881f547fdf,314117,193729,E6-MS-TMS-BUSI-WEB] INFO  c.e.p.t.c.c.e.E6TransformControllerAdviceProcessor - id换name耗时:3
  39. 2021-11-24 09:47:49.402 [http-nio-30020-exec-9] [24ee988678463fb3,aee8b388cf00d0cf,a1b9f8881f547fdf,314117,193729,E6-MS-TMS-BUSI-WEB] INFO  c.e.p.c.w.E6CommonFilter - /rpc/com.e6yun.project.tms.base.rpc.service.TmsBaseFixedLineRpcService/getFixedLineInfoByCorpIdAndLineIds, 请求耗时: 289 ms

实现

在网关，从MDC 中获取 traceId 设置到响应头

  1. @Component
  2. public class DefaultTraceFilter implements GlobalFilter, Ordered {
  4.     private static final String TRACE_ID_KEY = "e6api-trace-id";
  6.     @Override
  7.     public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
  8.         headerSetTraceId(exchange);
  9.         return chain.filter(exchange);
  10.     }
  11.     private void headerSetTraceId(ServerWebExchange exchange) {
  12.         String traceId = MDC.get("traceId");
  13.         if (StringUtils.isNotBlank(traceId)) {
  14.             ServerHttpResponse response = exchange.getResponse();
  15.             HttpHeaders headers = response.getHeaders();
  16.             headers.add(TRACE_ID_KEY, traceId);
  17.             exchange.mutate().response(response).build();
  18.         }
  19.     }
  21.     @Override
  22.     public int getOrder() {
  23.         return -11;
  24.     }
  25. }