Dubbo自定义日志拦截器

前言

上一篇文章 Spring aop+自定义注解统一记录用户行为日志记录了 web层中通过自定义注解配合Spring aop自动记录用户行为日志的过程。那么按照分布式架构中Dubbo服务层的调用过程是否也可以实现统一记录日志？自定义日志拦截器可以实现这个需求。

需求场景

在使用Dubbo搭建的分布式项目中，服务层代码调用是这样的:

     @GetMapping(value = "/info")
2    public BaseResult userInfo() {
3        //rpc远程调用用户服务
4        BaseResult result = mUserService.userInfo();
6        return result;
7    }

这里的用户服务位于另外一个服务进程，由服务提供者暴露出来，让web层远程调用，需要记录服务结果的调用过程，便于跟踪定位bug.

自定义日志拦截器

翻看下Dubbo官方文档，可以看到如下内容：

简要说明：

Dubbo 中所有的拦截器全部继承自org.apache.dubbo.rpc.Filter接口，我们自己也可以自行扩展，只要继承该接口即可.
用户自定义 filter 默认在内置 filter 之后执行

新增 DubboServiceFilter 拦截器如下：

public class DubboServiceFilter implements Filter {private static final Logger LOGGER = LoggerFactory.getLogger(DubboServiceFilter.class);@Overridepublic Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {//外部日志开关默认关闭String logSwitch = StringUtils.equals(RedisUtil.get(BaseConstants.CACHE_SERVICE_LOG_SWITCH), BaseConstants.YES) ? BaseConstants.YES : BaseConstants.NO;if (StringUtils.equals(BaseConstants.YES, logSwitch)) {//打印入参日志DubboServiceRequest serviceRequest = new DubboServiceRequest();serviceRequest.setInterfaceName(invocation.getInvoker().getInterface().getName());serviceRequest.setMethodName(invocation.getMethodName());serviceRequest.setArgs(invocation.getArguments());LOGGER.info("dubbo服务接口入参: " + JSON.toJSONString(serviceRequest));}//开始时间long startTime = System.currentTimeMillis();//执行接口调用逻辑Result result = invoker.invoke(invocation);//调用耗时long elapsed = System.currentTimeMillis() - startTime;//如果发生异常 则打印异常日志if (result.hasException() && invoker.getInterface() != GenericService.class) {LOGGER.error("dubbo执行异常: ", result.getException());} else {if (StringUtils.equals(BaseConstants.YES, logSwitch)) {//打印响应日志DubboServiceResponse serviceResponse = new DubboServiceResponse();serviceResponse.setMethodName(invocation.getMethodName());serviceResponse.setInterfaceName(invocation.getInvoker().getInterface().getName());serviceResponse.setArgs(invocation.getArguments());serviceResponse.setResult(new Object[]{result.getValue()});serviceResponse.setSpendTime(elapsed);LOGGER.info("dubbo服务响应成功,返回数据: " + JSON.toJSONString(serviceResponse));}}//返回结果响应结果return result;}
}

代码中对应的实体bean如下：

入参实体：

/*** @program: easywits* @description:Dubbo服务请求入参实体* @author: zhangshaolin* @create: 2019-01-08 20:35**/
@Data
public class DubboServiceRequest implements Serializable{private static final long serialVersionUID = 7127824956842786618L;/*** 接口名*/private String interfaceName;/*** 方法名*/private String methodName;/*** 参数*/private Object[] args;
}

响应实体：

/*** @program: easywits* @description: Dubbo服务响应结果实体* @author: zhangshaolin* @create: 2019-01-08 20:36**/
@Data
public class DubboServiceResponse implements Serializable{private static final long serialVersionUID = -2531169660859647737L;/*** 接口名*/private String interfaceName;/*** 方法名*/private String methodName;/*** 参数*/private Object[] args;/*** 返回结果*/private Object result;/*** 调用耗时(毫秒)*/private long spendTime;
}

在/src/main/resources/META-INF/dubbo目录下新增纯文本文件org.apache.dubbo.rpc.Filter 内容为：

dubboServiceFilter=com.easywits.common.filter.DubboServiceFilter

键值对形式,键随便起个名字
值为DubboServiceFilter拦截器的完整包名.

最后在服务提供者配置文件中添加配置使拦截器生效：

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"...省略部分代码"><!--服务提供方应用信息,用于计算依赖关系--><dubbo:application name="easywits-upms-rpc-service"/><!--用dubbo协议在20881端口暴露服务--><dubbo:protocol name="dubbo" port="20881" payload="52428800"/><!--自定义服务层过滤器，值为上述步骤文本文件中的键--><dubbo:provider filter="dubboServiceFilter"/>....省略部分服务配置
</beans>

验证结果

抓一下我们业务中的部分日志信息看下效果，如下图：

可以清楚地看到Dubbo服务接口调用的请求参数信息，以及最终的响应结果信息，便于定位线上问题。

参考文档：http://dubbo.apache.org/zh-cn/docs/dev/impls/filter.html

最后

记录一个比较简单的具体实用场景，后续会不定期更新更多的实用场景，欢迎关注公众号【张少林同学】！