SpringCloud之个性化日志追踪
方案背景
日志跟踪技术使得查找一次调用所产生的日志信息变得方便。当需要排查一些问题时，可以根据报错的上下文进行分析，给问题诊断带来方便。在spring cloud微服务中，单体应用的日志跟踪技术已经不能满足需求，因而一般采用Spring Cloud Sleuth组件提供的功能来完成分布式日志跟踪。
Spring Cloud Sleuth组件会在zuul网关中，对于每个请求生成一个日志id，之后会通过http header的方式将id带到不同的服务应用中。在特定应用中，通过sl4j及特定的日志输出架构（比如logback）实施单体应用的日志跟踪。
Spring Cloud Sleuth默认的解决方案是在一次请求所生产的每条日志中添加日志id，然后通过日志id来关联该次请求的日志信息。在某些业务场景，可能需要对默认的解决方案进行功能的扩展，比如：
业务上对日志id的格式有要求，比如需要从日志id中看出请求的时间点等。
出于监控的需求，需要在每条日志中加入客户端请求的ip信息等。
本方案便是通过扩展Spring Cloud Sleuth默认的解决方案的功能达到满足以上业务点。
实现分析
服务本身对traceId的处理。
Sleuth通过Filter的方式，在filter中对请求头的处理来实现traceId的追踪。
先判断http头中是否存在“X-B3-TraceId”，不存在，则生成新的traceId；存在，则以头X-B3-TraceId的值作为traceId。最后将X-B3-TraceId的值放到MDC中，以便日志输出中带上X-B3-TraceId。这样使得在本服务中，用户请求产生的日志输出都会带有traceId。
服务间对traceId的处理
在微服务中，服务A向服务B发起调用请求。那如何将A中的traceId传递给B呢？首先，先要了解服务A是如何调用服务B的。
1、网关接收到进行，进行请求转发
Sleuth在ZuulFilter（TracePreZuulFilter）中将traceId添加到http头X-B3-TraceId中，以便所转发请求对应的服务能从头中获取到traceId。同时还将traceId放到MDC中，以便本应用在输出日志时带traceId。
2、服务内部通过feign注解调用另一个服务
由于feign注解的实现是通过生成Hystrix的代理类来完成请求的处理，而Hystrix在进行请求发送时是通过异步的方式调用ribbon的组件进行负载均衡，然后通过Feign.Client的execute方法来进行请求的发送。故此时需要解决以下两个问题：
（1）如何在异步线程中传递traceId。
Sluth是通过实现HystrixConcurrencyStrategy接口来解决traceId异步传递的问题。Hystrix在实际调用时，会调用HystrixConcurrencyStrategy的wrapCallable方法。因此，通过实现这个接口，在wrapCallable中将traceId存放起来（具体参见SleuthHystrixConcurrencyStrategy
）。
（2）Feign如何在服务中传递traceId。
Sluth通过实现Feign.Client，在execute前将traceId存放到X-B3-TraceId头中来实现（具体参见TraceFeignClient）。
方案实施
网关生成额外的跟踪信息
实现ZuulFilter接口，在其run方法中将额外的信息放到http头中及MDC中。如下：
源码：
package com.yao.springcloud.filters;
import com.netflix.zuul.ZuulFilter;
import com.netflix.zuul.context.RequestContext;
import com.yao.springcloud.ConstantsName;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import java.util.Map;
public class TracePreFilter extends ZuulFilter {
private static Logger LOGGER = LoggerFactory.getLogger(TracePreFilter.class);
@Override
public String filterType() {
return "pre";
}
@Override
public int filterOrder() {
return 1;
}
@Override
public boolean shouldFilter() {
return true;
}
@Override
public Object run() {
LOGGER.info("TracePreFilter run");
RequestContext ctx = RequestContext.getCurrentContext();
Map<String, String> requestHeaders = ctx.getZuulRequestHeaders();
String clientIp = ctx.getRequest().getRemoteAddr();
//设置头信息
setHeader(requestHeaders, ConstantsName.CLIENT_IP, clientIp);
//添加到MDC中
MDC.put(ConstantsName.CLIENT_IP, clientIp);
LOGGER.info("TracePreFilter END");
return null;
}
/**
* 设置请求头
*
* @param request 请求头
* @param name 参数名
* @param value 参数值
*/
public void setHeader(Map<String, String> request, String name, String
value) {
if (value != null) {
request.put(name, value);
}
}
}
web filter中将额外的跟踪信息保存到MDC中
web filter将额外的跟踪信息从http header中取出来，然后放到MDC中。该步确保在一个服务中可以从MDC中获取到相关信息。
源码：
package com.yao.springcloud.web;
import com.yao.springcloud.ConstantsName;
import org.apache.commons.lang.StringUtils;
import org.slf4j.MDC;
import org.springframework.core.annotation.Order;
import org.springframework.web.filter.OncePerRequestFilter;
import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
@Order(ConstantsName.TRACE_FILTERORDER)
public class WebTraceFilter extends OncePerRequestFilter {
@Override
protected void doFilterInternal(HttpServletRequest httpServletRequest, HttpServletResponse httpServletResponse,
FilterChain filterChain) throws ServletException, IOException {
String clientIp = httpServletRequest.getHeader(ConstantsName.CLIENT_IP);
if(StringUtils.isNotEmpty(clientIp)){//如果为空，则表示第一次访问，即网关端的请求
MDC.put(ConstantsName.CLIENT_IP, clientIp);
}
filterChain.doFilter(httpServletRequest, httpServletResponse);
//确保每个应用处理完后 清除相关MDC的内容
MDC.remove(ConstantsName.CLIENT_IP);
}
}
在hystrix异步线程中添加额外的跟踪信息
该步骤主要是将MDC中添加的额外信息放到异步线程中，解决通过hystrix进行异步调用时无法在异步线程中取得所需要信息的问题。
源码：
package com.yao.springcloud.hystrix;
import com.netflix.hystrix.strategy.concurrency.HystrixConcurrencyStrategy;
import com.netflix.hystrix.strategy.eventnotifier.HystrixEventNotifier;
import com.netflix.hystrix.strategy.metrics.HystrixMetricsPublisher;
import com.netflix.hystrix.strategy.properties.HystrixPropertiesStrategy;
import com.yao.springcloud.ConstantsName;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.slf4j.MDC;
import org.springframework.cloud.sleuth.Span;
import org.springframework.cloud.sleuth.TraceKeys;
import org.springframework.cloud.sleuth.Tracer;
import org.springframework.cloud.sleuth.instrument.hystrix.SleuthHystrixConcurrencyStrategy;
import java.lang.invoke.MethodHandles;
import java.util.concurrent.Callable;
public class TraceSleuthHystrixConcurrencyStrategy extends SleuthHystrixConcurrencyStrategy {
private static final Log log = LogFactory.getLog(TraceSleuthHystrixConcurrencyStrategy.class);
private static final String HYSTRIX_COMPONENT = "hystrix";
private final Tracer tracer;
private final TraceKeys traceKeys;
private HystrixConcurrencyStrategy delegate;
public HystrixConcurrencyStrategy getDelegate() {
return delegate;
}
public void setDelegate(HystrixConcurrencyStrategy delegate) {
this.delegate = delegate;
}
public Tracer getTracer() {
return tracer;
}
public TraceKeys getTraceKeys() {
return traceKeys;
}
public TraceSleuthHystrixConcurrencyStrategy(Tracer tracer, TraceKeys traceKeys) {
super(tracer, traceKeys);
this.tracer = tracer;
this.traceKeys = traceKeys;
}
@Override
public <T> Callable<T> wrapCallable(Callable<T> callable) {
if (callable instanceof TraceHystrixTraceCallable) {
return callable;
}
Callable<T> wrappedCallable = this.delegate != null ? this.delegate.wrapCallable(callable) : callable;
if (wrappedCallable instanceof TraceHystrixTraceCallable) {
return wrappedCallable;
}
return new TraceHystrixTraceCallable<>(this.tracer, this.traceKeys, wrappedCallable);
}
private void logCurrentStateOfHysrixPlugins(HystrixEventNotifier eventNotifier,
HystrixMetricsPublisher metricsPublisher, HystrixPropertiesStrategy propertiesStrategy) {
if (log.isDebugEnabled()) {
log.debug("Current Hystrix plugins configuration is [" + "concurrencyStrategy [" + this.delegate
+ "]," + "eventNotifier [" + eventNotifier + "]," + "metricPublisher [" + metricsPublisher
+ "]," + "propertiesStrategy [" + propertiesStrategy + "]," + "]");
log.debug("Registering Sleuth Hystrix Concurrency Strategy.");
}
}
// Visible for testing
static class TraceHystrixTraceCallable<S> implements Callable<S> {
private static final Log log = LogFactory.getLog(MethodHandles.lookup().lookupClass());
private Tracer tracer;
private TraceKeys traceKeys;
private Callable<S> callable;
private String userIp;
private String accessPath;
private String userName;
private Span parent;
private String domain;
private String clientIp;
public Tracer getTracer() {
return tracer;
}
public void setTracer(Tracer tracer) {
this.tracer = tracer;
}
public TraceKeys getTraceKeys() {
return traceKeys;
}
public void setTraceKeys(TraceKeys traceKeys) {
this.traceKeys = traceKeys;
}
public Callable<S> getCallable() {
return callable;
}
public void setCallable(Callable<S> callable) {
this.callable = callable;
}
public String getUserIp() {
return userIp;
}
public void setUserIp(String userIp) {
this.userIp = userIp;
}
public String getAccessPath() {
return accessPath;
}
public void setAccessPath(String accessPath) {
this.accessPath = accessPath;
}
public String getUserName() {
return userName;
}
public void setUserName(String userName) {
this.userName = userName;
}
public Span getParent() {
return parent;
}
public void setParent(Span parent) {
this.parent = parent;
}
public TraceHystrixTraceCallable(Tracer tracer, TraceKeys traceKeys, Callable<S> callable) {
this.tracer = tracer;
this.traceKeys = traceKeys;
this.callable = callable;
this.parent = tracer.getCurrentSpan();
this.clientIp = MDC.get(ConstantsName.CLIENT_IP);
}
@Override
public S call() throws Exception {
Span span = this.parent;
boolean created = false;
MDC.put(ConstantsName.CLIENT_IP,this.clientIp);
if (span != null) {
span = this.tracer.continueSpan(span);
if (log.isDebugEnabled()) {
log.debug("Continuing span " + span);
}
} else {
span = this.tracer.createSpan(HYSTRIX_COMPONENT);
created = true;
if (log.isDebugEnabled()) {
log.debug("Creating new span " + span);
}
}
if (!span.tags().containsKey(Span.SPAN_LOCAL_COMPONENT_TAG_NAME)) {
this.tracer.addTag(Span.SPAN_LOCAL_COMPONENT_TAG_NAME, HYSTRIX_COMPONENT);
}
String asyncKey = this.traceKeys.getAsync().getPrefix()
+ this.traceKeys.getAsync().getThreadNameKey();
if (!span.tags().containsKey(asyncKey)) {
this.tracer.addTag(asyncKey, Thread.currentThread().getName());
}
try {
return this.callable.call();
} finally {
MDC.remove(ConstantsName.CLIENT_IP);
if (created) {
if (log.isDebugEnabled()) {
log.debug("Closing span since it was created" + span);
}
this.tracer.close(span);
} else if (this.tracer.isTracing()) {
if (log.isDebugEnabled()) {
log.debug("Detaching span since it was continued " + span);
}
this.tracer.detach(span);
}
}
}
}
}
在异步线程中发起http请求前，将信息添加到header中
hystrix在进行发送前会通过RequestInterceptor对请求信息进行预处理（见SynchronousMethodHandler->executeAndDecode->targetRequest方法）。因此，除了重写Feign.Client方法外，最简单的方式就是添加一个RequestInterceptor，在RequestInterceptor中将额外的跟踪信息添加到http头中。
源码：
package com.yao.springcloud.feign;
import feign.RequestInterceptor;
import feign.RequestTemplate;
/**
* Created by micat707 on 2017/6/5.
*/
public class TraceFeignRequestInterceptor implements RequestInterceptor {
/**
*
* apply:
*
* @return void
* @author：micat707
* @date：2017年11月4日 下午4:53:59
*/
@Override
public void apply(RequestTemplate template) {
TraceFeignRequestTemplateInjector.inject(template);
}
}
package com.yao.springcloud.feign;
import com.yao.springcloud.ConstantsName;
import feign.RequestTemplate;
import org.slf4j.MDC;
import org.springframework.util.StringUtils;
public class TraceFeignRequestTemplateInjector {
public static void inject(RequestTemplate carrier) {
String clientIp = MDC.get("CLIENT_IP");
setHeader(carrier, ConstantsName.CLIENT_IP, clientIp);
}
protected static void setHeader(RequestTemplate request, String name,
String value) {
if (StringUtils.hasText(value) && !request.headers().containsKey(name)) {
request.header(name, value);
}
}
}
附
源码地址：https://github.com/micat707/myprojects/tree/master/spring-cloud-solutions
