dubbo全链路日志追踪实践
想做到日志完整的链路追踪,实现原理很简单,为每一个请求创造一个唯一标识(traceId),我们通过traceId来查找对应web层,service层中的具体代码日志,同时我们可以统计其他相关信息.
(网上好多铁子都瞎写,要不就复制粘贴,仔细看这篇保证你能弄出来,没异常)
假设现在目前项目结构:
web(放controller的),userService(放mapper.xml的), productServuce(也是放mapper.xml的 ),…(这里仅以web项目 ,productService为例)
针对web我们为每一个请求分发traceId好说因为我们可以创建拦截器和过滤器都可实现,问题在于,当web通过zookeeper调用对应service时如何将traceId 传递下去,这里需要用到一个对象RpcContext
下边代码为具体实践过程
(题外话,目前我的项目采用dubbo2.7.6的版本,请注意将对应的dubbo-spring-boot-starter升级到一致的版本,别问为啥)
web项目创建拦截器并创建traceId,代码里ResourcesUtil.TRACEID 只是一个字符串 “traceId”
package ****.web.filter;
import lombok.extern.slf4j.Slf4j;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;
import org.springframework.web.servlet.HandlerInterceptor;
import org.springframework.web.servlet.ModelAndView;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.UUID;
@Slf4j
@Component
public class TraceIdInterceptor implements HandlerInterceptor {
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
// generate traceId
String traceId = UUID.randomUUID().toString().replace("-", "");
request.setAttribute(ResourcesUtil.TRACEID,traceId);
// put traceId
Context.initialLocal(request);
log.info("web拦截器请求拦截,地址: "+request.getRequestURI() + " traceId: " + traceId);
return true;
}
@Override
public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
}
}
web创建Context作为util存在即可
package ****.web.utils;
import org.apache.catalina.connector.Request;
import org.apache.logging.log4j.ThreadContext;
import javax.servlet.http.HttpServletRequest;
public class Context {
private static final ThreadLocal<HttpServletRequest> REQUEST_LOCAL = new ThreadLocal<>();
public final static void initialLocal(HttpServletRequest request) {
if (null == request) {
return;
}
ThreadContext.put(ResourcesUtil.TRACEID, request.getAttribute(ResourcesUtil.TRACEID)+"");
REQUEST_LOCAL.set(request);
}
public static HttpServletRequest getCurrentRequest() {
return REQUEST_LOCAL.get();
}
}
为webStarter添加拦截器
拦截器加完了,到这里你每一个web接口请求都会有一个traceId了,所以我们现在修改下接口返回值,将这个值返回给调用者,不管他用不用.
系统全接口统一返回值
package **.common.util;
import com.fasterxml.jackson.annotation.JsonInclude;
import com.fasterxml.jackson.annotation.JsonInclude.Include;
import **.common.util.error.ErrorCode;
import io.swagger.annotations.ApiModelProperty;
import lombok.Data;
import lombok.experimental.Accessors;
import java.io.Serializable;
import java.text.SimpleDateFormat;
import java.util.Date;
@Data
@Accessors(chain = true)
public class ApiResponse<T> implements Serializable {
@ApiModelProperty(value = "返回代码")
private int code = ErrorCode.NO_ERROR.getCode();
@ApiModelProperty(value = "返回信息")
private String msg = ErrorCode.NO_ERROR.getMessage();
@ApiModelProperty(value = "返回时间")
private String timestamp=getNowDate();
@ApiModelProperty(value = "返回数据")
@JsonInclude(Include.NON_NULL)
private T result;
//注意这里是新增的属性traceID接口请求的唯一标识
private String traceId;
public ApiResponse() {
super();
}
public ApiResponse(T t) {
this.result = t;
}
public ApiResponse(ErrorCode protocolErrorCode) {
this.code = protocolErrorCode.getCode();
this.msg = protocolErrorCode.getMessage();
}
public ApiResponse(ErrorCode protocolErrorCode, String msg) {
this.code = protocolErrorCode.getCode();
this.msg = msg;
}
public static String getNowDate() {
Date currentTime = new Date();
SimpleDateFormat formatter = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss");
return formatter.format(currentTime);
}
}
创建ResponseModifyAdvice类在接口返回数据之前我们需要对它改造下
package *.web.conf;
import *.common.util.ApiResponse;
import *.common.util.PageResponse;
import *.common.util.error.ResourcesUtil;
import org.slf4j.MDC;
import org.springframework.core.MethodParameter;
import org.springframework.http.MediaType;
import org.springframework.http.converter.HttpMessageConverter;
import org.springframework.http.server.ServerHttpRequest;
import org.springframework.http.server.ServerHttpResponse;
import org.springframework.web.bind.annotation.ControllerAdvice;
import org.springframework.web.servlet.mvc.method.annotation.ResponseBodyAdvice;
@ControllerAdvice
public class ResponseModifyAdvice implements ResponseBodyAdvice<Object> {
@Override
public boolean supports(MethodParameter methodParameter, Class<? extends HttpMessageConverter<?>> aClass) {
return true;
}
@Override
public Object beforeBodyWrite(Object o, MethodParameter methodParameter, MediaType mediaType, Class<? extends HttpMessageConverter<?>> aClass, ServerHttpRequest serverHttpRequest, ServerHttpResponse serverHttpResponse) {
if(o instanceof ApiResponse){
((ApiResponse) o).setTraceId(MDC.get(ResourcesUtil.TRACEID));
}
return o;
}
}
到此为止,你的web项目现在在访问接口的时候,是不都有了一个traceId,
下边开始解决,web中如何将这个traceId传递给对应的提供者
也是蛮简单的,通过dubbo的拦截器实现,当我们web应用调用对应的service时,web是消费者,对应的service就是提供者,所以我们要为web中dubbo.consumer配置filter属性
过滤器实现代码如下
package *.web.filter;
import com.alibaba.dubbo.common.extension.Activate;
import *.common.util.RedisUtil;
import *.web.utils.Context;
import *.common.util.error.ResourcesUtil;
import lombok.extern.slf4j.Slf4j;
import org.apache.dubbo.rpc.*;
import javax.annotation.Resource;
import javax.servlet.http.HttpServletRequest;
/**
* @author wzd
*/
@Slf4j
@Activate(group = {"consumer"})
public class WebLogFilter implements Filter {
@Resource
private RedisUtil redisUtil;
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
//1.从ThreadLocal获取请求信息
HttpServletRequest request = Context.getCurrentRequest();
//2.将Context参数放到RpcContext
RpcContext rpcCtx = RpcContext.getContext();
Context.initialLocal(request);
String token = request.getHeader("token");
String traceId = (String) request.getAttribute(ResourcesUtil.TRACEID);
rpcCtx.setAttachment(ResourcesUtil.TRACEID, traceId);
log.info("web请求拦截,地址: "+invoker.getUrl() + " traceId: " + request.getAttribute(ResourcesUtil.TRACEID));
// if(redisUtil == null){
// BeanFactory factory = WebApplicationContextUtils.getRequiredWebApplicationContext(request.getServletContext());
// redisUtil = (RedisUtil) factory.getBean("redisUtil");
// }
// redisUtil.getModel(redisUtil.getUserTokenKey(TokenUtil.getJWTUserName(token), TokenUtil.getJWTUserType(token)), UserToken.class);
log.info("请求用户token: "+token);
return invoker.invoke(invocation);
}
}
修改配置文件(因为我们是多配置,具体改哪个文件你自己变通下)
另外需要创建文件在META-INF.dubbo下 文件名:com.alibaba.dubbo.rpc.Filter
内容如下
webLogFilter= **.web.filter.WebLogFilter
NOTE ! dubbo.consumer.filter配置的名称就是文本文件中的key 别瞎写
至此web项目中所有配置就都ok了接下来是要配置提供者的项目了,原理一样,这里不赘述直接上代码
创建文本文件,因为service有可能既是消费者又是提供者所以两个都拦截
package *.product.filter;
import com.alibaba.fastjson.JSONObject;
import *.common.util.error.ResourcesUtil;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.apache.dubbo.common.extension.Activate;
import org.apache.commons.lang3.StringUtils;
import org.apache.dubbo.rpc.RpcContext;
import org.slf4j.MDC;
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 java.util.UUID;
/**
*/
//@Activate(group = {"consumer"})
public class ConsumerRpcTraceFilter implements Filter {
Log log = LogFactory.getLog(ConsumerRpcTraceFilter.class);
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
// 获得 RPC 方法名
String methodName = invoker.getUrl().getPath();
// 获得开始时间
long startTime = System.currentTimeMillis();
String traceId = RpcContext.getContext().getAttachment(ResourcesUtil.TRACEID);
if (StringUtils.isBlank(traceId)) {
traceId = this.getUUID() ;
}
Object[] arguments = invocation.getArguments();
log.info("消费者拦截请求, traceId:" + traceId + " methodName: " + methodName + "startTime: " + startTime + " arguments: " + JSONObject.toJSONString(arguments));
//设置日志traceId变量
MDC.put(ResourcesUtil.TRACEID, traceId);
RpcContext.getContext().setAttachment(ResourcesUtil.TRACEID, traceId);
try{
Result result = invoker.invoke(invocation);
// 抛出的异常
Throwable exception = result.getException();
// 返回结果
Object value = result.getValue();
// 打印结束日志
if (exception != null) {
log.info("消费者拦截请求结束,traceId: "+traceId + "耗时:"+(System.currentTimeMillis() - startTime) + "毫秒,响应结果异常:" + exception.getMessage());
} else {
log.info("消费者拦截请求结束, traceId: " +traceId+"耗时:"+(System.currentTimeMillis() - startTime) + "毫秒,响应结果:" + JSONObject.toJSONString(value));
}
return result;
}finally {
MDC.remove(ResourcesUtil.TRACEID);
}
}
/**
* 获取UUID
* @return String UUID
*/
public String getUUID(){
String uuid = UUID.randomUUID().toString();
//替换-字符
return uuid.replaceAll("-", "");
}
}
package *.product.filter;
import com.alibaba.fastjson.JSONObject;
import *.common.util.error.ResourcesUtil;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.apache.commons.lang3.StringUtils;
import org.apache.dubbo.rpc.RpcContext;
import org.slf4j.MDC;
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 java.util.UUID;
/**
* @author wzd
*/
//@Activate(group = {"provider"},order = 1)
public class ProviderRpcTraceFilter implements Filter {
Log log = LogFactory.getLog(ConsumerRpcTraceFilter.class);
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
// 获得 RPC 方法名
String methodName = invoker.getUrl().getPath();
// 获得开始时间
long startTime = System.currentTimeMillis();
String traceId = RpcContext.getContext().getAttachment(ResourcesUtil.TRACEID);
if (StringUtils.isBlank(traceId)) {
traceId = this.getUUID() ;
}
Object[] arguments = invocation.getArguments();
log.info("提供者拦截请求, traceId:" + traceId + " methodName: " + methodName + "startTime: " + startTime + " arguments: " + JSONObject.toJSONString(arguments));
//设置日志traceId变量
MDC.put(ResourcesUtil.TRACEID, traceId);
RpcContext.getContext().setAttachment(ResourcesUtil.TRACEID, traceId);
try{
Result result = invoker.invoke(invocation);
// 抛出的异常
Throwable exception = result.getException();
// 返回结果
Object value = result.getValue();
// 打印结束日志
if (exception != null) {
log.info("提供者拦截请求结束,traceId: "+traceId + "耗时:"+(System.currentTimeMillis() - startTime) + "毫秒,响应结果异常:" + exception.getMessage());
} else {
log.info("提供者拦截请求结束, traceId: " +traceId+"耗时:"+(System.currentTimeMillis() - startTime) + "毫秒,响应结果:" + JSONObject.toJSONString(value));
}
return result;
}finally {
MDC.remove(ResourcesUtil.TRACEID);
}
}
/**
* 获取UUID
* @return String UUID
*/
public String getUUID(){
String uuid = UUID.randomUUID().toString();
//替换-字符
return uuid.replaceAll("-", "");
}
}
修改配置文件 (provider中-exception可以忽略掉)
测试
swagger接口测试
web控制台
对应的service(如果统一项目部署在多台机器上效果一样)
最后,因为添加过滤器肯定会对接口响应速度有所影响,所以我将其中redis获取用户信息代码注释掉,具体影响如何看下图,想加就加吧