一、問題背景
為了方便運(yùn)維日常定位排查問題時(shí),使用traceId查詢日志時(shí)可以完整的查看當(dāng)前業(yè)務(wù)請求的完整日志鏈路,需使用traceId(日志跟蹤號)將日志串聯(lián)起來。
系統(tǒng)采用LogBack日志組件,在輸出日志時(shí)輸出_traceId日志跟蹤號,logback.xml配置如下:
../log/${ServerName}/${AppName}.log ../log/${ServerName}/${AppName}.log.%d{yyyy-MM-dd} 7 %d{HH:mm:ss.SSS} %-5level [%.15thread][%X{_traceId}] %logger{36} – %.-4096msg%n
公司系統(tǒng)采用分布式架構(gòu),從接收到請求到業(yè)務(wù)處理完成并返回,涉及SpringMVC入口、服務(wù)間dubbo調(diào)用、基于RocketMQ實(shí)現(xiàn)的業(yè)務(wù)解耦、以及來自第三方渠道的http通知回調(diào)。
現(xiàn)在的問題是從業(yè)務(wù)請求入口到返回業(yè)務(wù)響應(yīng),如何使用同一traceId將日志做串聯(lián)?
二、解決方案
在介紹具體解決方案之前,首先介紹下Slf4j日志框架的MDC機(jī)制。映射診斷上下文(Mapped Diagnostic Context,簡稱MDC)可以簡單理解為當(dāng)前日志線程的上下文,也是一個(gè)k-v格式的map結(jié)構(gòu)。
當(dāng)服務(wù)器幾乎同時(shí)處理多個(gè)請求時(shí),日志輸出通常是交錯(cuò)的,而MDC是基于每個(gè)線程進(jìn)行管理的,子線程自動繼承其父線程的MDC的副本。可以通過往MDC里塞入traceId,達(dá)到串聯(lián)日志的目的。
以下為MDC填充獲取traceId方法:
public final static String TRACE_ID = “_traceId”;static private String generateTraceId() { return UUID.randomUUID().toString().replaceAll(“-“, “”);}public static String getTraceId() { return MDC.get(TRACE_ID);}public static void setTraceId(String traceId) { MDC.put(TRACE_ID, traceId);}public static void clearTrace() { MDC.remove(TRACE_ID);}public static void initTrace() { String traceId = generateTraceId(); setTraceId(traceId);}
2.1、接收http請求時(shí)的日志鏈路串聯(lián)
解決思路:可以從HttpServletRequest獲取traceId并塞到MDC中。
具體如下:
public static void initTraceFromRequest(HttpServletRequest request) { String traceId; // 從前端表單提交里獲取traceId traceId = request.getParameter(TRACE_ID); if (StringUtils.isNotBlank(traceId)) { setTraceId(traceId, request); return; } // 從forward后端轉(zhuǎn)發(fā)請求里獲取traceId traceId = (String) request.getAttribute(TRACE_ID); if (StringUtils.isNotBlank(traceId)) { setTraceId(traceId, request); return; } // 從請求url路徑中里獲取traceId Map pathVariables = (Map) request.getAttribute(HandlerMapping.URI_TEMPLATE_VARIABLES_ATTRIBUTE); if (pathVariables != null) { traceId = (String) pathVariables.get(TRACE_ID); } if (StringUtils.isNotBlank(traceId)) { setTraceId(traceId, request); return; } // 以上都獲取不到的話,就生成一個(gè)traceId并填充到MDC以及Session中 traceId = generateTraceId(); setTraceId(traceId, request);}
具體解決方案:使用SpringMVC攔截器機(jī)制攔截所有web請求,獲取并串聯(lián)traceId。
public class LogTraceInterceptor extends HandlerInterceptorAdapter { @Autowired private ConfigBean configBean; @Override public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception { if(handler instanceof HandlerMethod) { TraceUtil.initTraceFrom(request); } return true; } @Override public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception { }}
實(shí)際測試時(shí)發(fā)現(xiàn)如下問題:
后臺controller間有redirect重定向或forward轉(zhuǎn)發(fā)跳轉(zhuǎn)時(shí),跳轉(zhuǎn)前后的日志traceId沒有串聯(lián)上。
分析如下:
- 1、redirect重定向前后是兩個(gè)不同的request,就算攔截器攔截到也是跳轉(zhuǎn)后的request,沒法串聯(lián)上跳轉(zhuǎn)前的traceId。
- 2、forward轉(zhuǎn)發(fā)前后是同一個(gè)request,但是不同于redirect重定向跳轉(zhuǎn),forward跳轉(zhuǎn)系服務(wù)器內(nèi)部跳轉(zhuǎn),不經(jīng)過攔截器,依舊無法串聯(lián)traceId。
針對上述問題,解決方案如下:
1、針對redirect跳轉(zhuǎn),將traceId存到session中,通過session串聯(lián)traceId。
traceId = (String)request.getSession().getAttribute(DataConstants.TRACE_ID);if(StringUtils.isNotBlank(traceId)) { setTraceId(traceId, request); return;}
2、針對forward跳轉(zhuǎn),由于是服務(wù)器內(nèi)部跳轉(zhuǎn),沒有找到可用的攔截手段,只能在forward轉(zhuǎn)發(fā)后的controller入口處主動調(diào)用initTraceFromRequest()方法,從request中獲取traceId。
2.2、dubbo調(diào)用間的日志鏈路串聯(lián)
解決思路:dubbo調(diào)用一樣有上下文的概念RpcContext,可以將traceId塞到RpcContext中達(dá)到dubbo調(diào)用間傳遞traceId。
具體如下:
// 往RPCContext填充traceIdpublic static void initTraceFrom(RpcContext context) { String traceId = (String) context.getAttachment(TRACE_ID); if (traceId == null) { traceId = generateTraceId(); } setTraceId(traceId);}// 從RPCContext獲取traceIdpublic static void putTraceInto(RpcContext context) { String traceId = getTraceId(); if (traceId != null) { context.setAttachment(TRACE_ID, traceId); }}
具體解決方案:使用Filter過濾器攔截dubbo調(diào)用,獲取或填充traceId。
public class TraceDubboFilter implements Filter { @Override public Result invoke(Invoker invoker, Invocation invocation) throws RpcException { RpcContext context = RpcContext.getContext(); if (context.isConsumerSide()) { TraceUtil.putTraceInto(context); } else if (context.isProviderSide()) { TraceUtil.initTraceFrom(context); } return invoker.invoke(invocation); }}
3.3、MQ異步處理時(shí)的日志鏈路串聯(lián)
解決思路:RocketMQ消息可以通過MessageExt.getUSerProperty()/setUserProperty()來獲取或設(shè)置traceid。
//生產(chǎn)者填充traceIdpublic static void putTraceInto(MessageExt msg) { String traceId = getTraceId(); if (traceId != null) { message.putUserProperty(TRACE_ID, traceId);; }}//消費(fèi)者獲取traceIdpublic static void initTraceFrom(MessageExt msg) { String traceId = msg.getUserProperty(TRACE_ID); if (traceId == null) { traceId = generateTraceId(); } setTraceId(traceId);}
具體解決方案:使用RocketMQ的消息過濾器MessageFilter統(tǒng)一攔截消息,獲取traceId。
public class MessageFilterImpl implements MessageFilter{ public boolean match(MessageExt msg, FilterContext arg1) { initTraceFrom(msg); return true; }}
3.4、http調(diào)用第三方服務(wù)時(shí)回調(diào)串聯(lián)traceId
解決思路:在上送給第三方的通知回調(diào)地址url中拼上_traceId
具體解決方案如下:
@RequestMapping(“/notify.do/{orderId}/{createTime}/{_traceId}”)public void receiveNotify(HttpServletRequest request, HttpServletResponse response, @PathVariable(“orderId”) String id, @PathVariable(“createTime”) String time, @PathVariable(“_traceId”) String traceId) {}