近期在做甲方的项目,里面用的技术体系很老,非 spring boot项目,是 jdk 8 + spring + spring mvc + tomcat + jsp 的方式,在这里记录一下完整的处理过程。
之前做的项目使用的是 spring cloud sleuth,这边不让加一些其他依赖,所以这个否决了,鉴于后面线上排查问题方便,不想翻全部日志,考虑到之前在美团用的TraceId,没用到spring cloud sleuth,所以,想看看是否有其他办法。
请求发起是 http ,然后通过 dubbo调用其他服务或者通过 http 再调用其他服务。
使用的日志有logback,log4j 1.x,目前中有 slf4j这个日志门面,所以,就考虑到了 MDC 功能,通过在 MDC 中加入 TraceId在日志中打印,实现好定位。
入口
通常是页面发起请求,如下
TraceFilter.java
/** * 请求过滤器,添加TraceId到MDC中 */ @Component public class TraceFilter extends OncePerRequestFilter implements Ordered { private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass()); @Override public int getOrder() { return Ordered.HIGHEST_PRECEDENCE; } @Override protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException { try { String traceId = request.getHeader("TraceId"); // 如果 http 请求头中没有 TraceId,则生成一个,否则使用请求头中的 TraceId if (StringUtils.isBlank(traceId)) { log.info("request header TraceId is blank"); traceId = UUID.randomUUID().toString(); } TraceIDUtils.setTraceId(traceId); MDC.put("TraceId", TraceIDUtils.getTraceId()); log.info("doFilterInternal start"); filterChain.doFilter(request, response); } finally { TraceIDUtils.removeTraceId(); MDC.clear(); log.info("doFilterInternal finish"); } } }调用完后记得清理 ThreadLocal 和 MDC,不然会造成内存泄漏和数据污染。
TraceIDUtils.java
public class TraceIDUtils { private static final ThreadLocal<String> TRACE_ID = new ThreadLocal<String>(); public static String getTraceId() { return TRACE_ID.get(); } public static void setTraceId(String traceId) { TRACE_ID.set(traceId); } public static void removeTraceId() { TRACE_ID.remove(); } }需要考虑到网络调用是其他服务发起的情况,就是需要在http 发起调用时把 MDC 中的 TraceId 加入到请求头中就可以,这样就能串联起来了。 添加如下代码
HttpHeaders headers = new HttpHeaders(); headers.add("TraceId", MDC.get("TraceId"));日志
把类的全路径和方法名,还有代码行号都打印出来。
logback配置
%date [%thread] %X{logId} %-5level-[%X{TraceId}]-[%logger#%method:%line]-%msg%nlog4j 1.x配置
[%d{yyyy-MM-dd HH:mm:ss SSS}]-[%t]-[%p]-[%X{TraceId}]-[%c#%M:%L]-%m%n这样就可以解决了单服务内调用的问题,现在的问题是项目之间跨服务调用的,使用了 dubbo,所以,做如下配置。
rpc(dubbo)
使用的是 dubbo 2.6.x版本,在各自的项目中添加如下文件
src/main/resources/META-INF/dubbo/com.alibaba.dubbo.rpc.Filter
需要声明生产者和消费者的过滤器,如下
消费者
import com.alibaba.dubbo.common.Constants; import com.alibaba.dubbo.common.extension.Activate; import com.alibaba.dubbo.rpc.Filter; import com.alibaba.dubbo.rpc.Invocation; import com.alibaba.dubbo.rpc.Invoker; import com.alibaba.dubbo.rpc.Result; import com.alibaba.dubbo.rpc.RpcContext; import com.alibaba.dubbo.rpc.RpcException; import org.apache.commons.lang3.StringUtils; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.slf4j.MDC; import java.lang.invoke.MethodHandles; @Activate(group = Constants.CONSUMER) public class WebTraceConsumerFilter implements Filter { private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass()); private static final String TRACE_ID_KEY = "TraceId"; @Override public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException { // 从当前线程的 MDC 中取出 TraceId String traceId = MDC.get(TRACE_ID_KEY); // log.info("invoke traceId={}", traceId); if (StringUtils.isNotBlank(traceId)) { // 将 TraceId 设置到 Dubbo 的隐式参数(Attachment)中,传递给服务端 // log.info("invoke set traceId into RpcContext traceId={}", traceId); RpcContext.getContext().setAttachment(TRACE_ID_KEY, traceId); } // log.info("invoke real invoke start traceId={}", traceId); Result invoke = invoker.invoke(invocation); // log.info("invoke real invoke finish traceId={}", traceId); return invoke; } }配置文件中添加如下
webTraceConsumerFilter=xxx.filter.WebTraceConsumerFilter生产者
import com.alibaba.dubbo.common.Constants; import com.alibaba.dubbo.common.extension.Activate; import com.alibaba.dubbo.rpc.Filter; import com.alibaba.dubbo.rpc.Invocation; import com.alibaba.dubbo.rpc.Invoker; import com.alibaba.dubbo.rpc.Result; import com.alibaba.dubbo.rpc.RpcException; import org.apache.commons.lang3.StringUtils; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.slf4j.MDC; import java.lang.invoke.MethodHandles; @Activate(group = Constants.PROVIDER) public class ServiceTraceProviderFilter implements Filter { private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass()); private static final String TRACE_ID_KEY = "TraceId"; @Override public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException { // 1. 从 Dubbo 请求参数中获取由消费端传递的 TraceId String traceId = invocation.getAttachment(TRACE_ID_KEY); // log.info("invoke remote traceId={}", traceId); // 2. 如果获取不到,说明是直连请求或上游未传递,此处可降级生成新ID或留空 if (StringUtils.isNotBlank(traceId)) { // log.info("invoke MDC.put traceId={}", traceId); MDC.put(TRACE_ID_KEY, traceId); } try { // log.info("invoke real invoke start traceId={}", traceId); // 3. 执行真正的业务逻辑 Result invoke = invoker.invoke(invocation); // log.info("invoke real invoke finish traceId={}", traceId); return invoke; } finally { // log.info("invoke MDC.remove traceId={}", traceId); // 4. 清理 MDC,防止内存泄漏或线程复用导致的下一个请求错乱 if (StringUtils.isNotBlank(traceId)) { MDC.remove(TRACE_ID_KEY); } } } }配置文件中添加如下
serviceTraceProviderFilter=xxx.filter.ServiceTraceProviderFilter最后
项目启动后,测试了一个跨服务调用,包含 dubbo 、 http 调用的,全链路日志打印正常,通过 TraceId 精准匹配到对应的业务日志。