Dubbo的Filter机制为我们做应用的扩展设计提供了很多可能性,这里的Filter也是“责任链”机制的一种实现场景,作为Java码农,我们也经常接触到很多责任链的实现场景,如Tomcat进入Servlet前的filter,如Spring Aop代理的链式调用等。本篇文章通过一个实例来看看Dubbo自定义Filter的代码具体如何编写。
我们为Dubbo实现Filter扩展的时候,一般是分为两个方向来做
1.服务消费者发起调用的流程
2.服务提供者接收请求的流程
如上图所示,无论当服务消费者发起调用时,还是服务提供者接收请求时,都会走过一条filter链,我们要做的就是往这个filter链中加入我们自己的filter,也就是图中的“自定义FIlter”这块内容。
本次编码目标
实现功能:
- 服务消费者发起调用时,打印请求信息,收到返回结果后,打印返回信息与整体调用耗时。
- 服务提供者收到请求时,打印请求信息,Service方法执行完后,打印返回信息与Service方法执行耗时。
- 服务消费者在发起调用时,带上trace_id,服务提供者收到请求后,拿到trace_id并通过MDC加到本次执行线程中,打印日志时打印出trace_id。以便通过日志跟踪一次请求的完整链路。
编码实现
项目结构如下,一个consumer服务,一个provider服务,外加一个api接口的定义包。
api中定义了一个接口,用来根据userId获取用户信息
public interface IUserService {
UserInfoDTO getUserInfo(Integer uerId);
}
provider项目中有这个接口的实现类,并向外暴露作为Dubbo的一个服务提供者。
@DubboService
@Slf4j
public class UserServiceImpl implements IUserService {
@Override
public UserInfoDTO getUserInfo(Integer userId) {
log.info("进入到getUserInfo方法了");
RoleDTO rolePO1 = new RoleDTO(1,"质检员");
RoleDTO rolePO2 = new RoleDTO(2,"初审员");
return new UserInfoDTO(userId,"张三",Arrays.asList(rolePO1,rolePO2));
}
}
涉及到的pojo类就不再展示了,Service功能不是本次的编码的关注点,所以简单点,所有的userId都返回同样的用户数据,都叫“张三”,角色都是“质检员、初审员”。
接口定义及实现类有了,接下来就开始编写Filter。
Filter类需要实现接口org.apache.dubbo.rpc.Filter,实现invoke接口。
1.消费端编码
trace_id相关的Filter实现
这个Filter实现的功能为,将当前线程中的trace_id加入到RpcContext的附加参数中,当RPC请求发出后,服务端也能够从RpcContext的附加参数中获取到这个trace_id。
public class DubboConstant {
public static final String TRACE_ID = "trace_id";
}
@Slf4j
@Activate(group = CommonConstants.CONSUMER, order = 1)
public class ConsumerTraceFilter implements Filter {
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
RpcContext rpcContext = RpcContext.getContext();
// 首先获取当前线程中的traceId,如果为空的话就new一个
String traceId = MDC.get(DubboConstant.TRACE_ID);
if(StringUtils.isBlank(traceId)) {
traceId = UUID.fastUUID().toString();
}
rpcContext.setAttachment(DubboConstant.TRACE_ID,traceId);
return invoker.invoke(invocation);
}
}
日志相关的Filter实现
这个Filter实现的功能为,在发起RPC请求前,将远程服务的ip端口及本次请求的参数打印出来。在收到返回结果后,打印本次调用耗时及结果信息。
@Slf4j
@Activate(group = CommonConstants.CONSUMER, order = 2)
public class ConsumerLogFilter implements Filter {
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
String host = invoker.getUrl().getHost();
int port = invoker.getUrl().getPort();
String serviceName = invocation.getTargetServiceUniqueName();
String methodName = invocation.getMethodName();
Object[] arguments = invocation.getArguments();
// 这里的traceId是在TraceFilter放进到RpcContext里的
String traceId = RpcContext.getContext().getAttachment(DubboConstant.TRACE_ID);
log.info("[send request] trace_id:{}, host:{}, port:{}, serviceName:{}, methodName:{}, arguments:{}", traceId, host, port, serviceName, methodName, arguments);
StopWatch stopWatch = new StopWatch();
stopWatch.start();
Result result = invoker.invoke(invocation);
stopWatch.stop();
long totalTimeMillis = stopWatch.getTotalTimeMillis();
log.info("[receive response] trace_id:{}, elapsed time:{}ms, response:{}", traceId, totalTimeMillis, result.getValue().toString());
return result;
}
}
SPI配置
要想使自定义的Filter生效,需要将Filter声明到一个文件中,dubbo会自动去这个文件中加载你设置的Filter,如果你写了Filter却没有声明到这个文件中,那么它也是不生效的。
这个文件就是 resources/META-INF/dubbo/org.apache.dubbo.rpc.Filter ,这是一个纯文本文件,内容如下
rpcLogFilter=com.hml.consumer.filter.ConsumerLogFilter
traceFilter=com.hml.consumer.filter.ConsumerTraceFilter
每个Filter都单独占一行,每行的格式为 [FIlter名字]:[自定义Filter的全限定名]。 其中Filter名字可以随便定义,没有固定格式。
这里我们将刚才写的两个FIlter加进去了。
另外,有一点要注意,这是我的实际踩坑经验,那就是META-INF.dubbo这个东西,它是两个文件夹,在使用idea建文件夹的时候最好一个一个建,先建META-INF,再建dubbo。否则,如果只建一个文件,文件名叫“META-INF.dubbo”的话,idea不会替你分成两个文件夹,它就仍然只是一个文件夹,文件名就叫“META-INF.dubbo”,Dubbo项目启动时也不会去找这个文件夹,注意注意!!!
配置Filter的生效范围
Filter的生效范围 首先分为两类:1.在服务消费者发起调用时生效,2.在服务提供者接收请求时生效
而每个大类里有分为两种生效范围:1.针对某个接口类下的接口生效 2.针对所有接口生效
官方提供了两种方式来配置FIlter的生效范围:通过配置文件的方式 和 通过注解的方式
目前大家暴露或调用dubbo接口的方式一般是使用注解了,几乎不用xml形式的配置了,所以对于1,3 两种针对单个接口的方式,一般是直接声明在 @DubboReference 或 @DubboService 注解中,例如
@DubboReference(filter = {"traceFilter"})
@DubboService(filter = "xxxFilter")
对于2,4 两种全局Filter,目前两种方式都有见到(我们本次编码的FIlter都属于全局Filter)
通过配置文件的方式
在application.properties配置文件中加入如下配置
// 配置服务消费者调用时生效的Filter
dubbo.consumer.filter=traceFilter,rpcLogFilter
// 配置服务提供者接收请求时生效的FIlter
dubbo.provider.filter=xxxFilter
traceFilter与rpcLogFilter就是我们在resources/META-INF/dubbo/org.apache.dubbo.rpc.Filter 这个文件中给FIlter设置的名字。
两个Filter的调用顺序就是上面的配置配好的顺序,traceFilter在前,rpcLogFilter在后。
通过注解的方式
使用@Activate注解同样也可以声明FIlter的生效范围及排序,我本次编码使用的就是该注解,在展示Filter代码时已经展示出来了。
例如
group代表了该FIlter的生效范围
对于group的值,我们一般使用org.apache.dubbo.common.constants.CommonConstants中设置好的值,常用到的就是这两个值
- CommonConstants.CONSUMER 代表服务消费者发起调用时生效
- CommonConstants.PROVIDER 代表服务提供者接收请求时生效
order代表了该Filter在自定义FIlter链中的顺序
order是个int值,值越小,顺序越靠前,越先被执行
Consumer编码总结
上面描述的自定义Filter编码过程其实一共分成了三步,三步完成后,Consumer端的Filter就配置好了
- 首先编码自定义FIlter类。
- 在resources/META-INF/dubbo/org.apache.dubbo.rpc.Filter这个配置文件中声明自定义Filter。
- 通过注解或配置文件的方式,声明Filter的生效范围及执行顺序。
2.服务提供端编码
服务提供端的FIlter编码同消费端编码,也是分为三步。第二步和第三步没什么可说的了,我们这里仅看FIlter的实现即可。
trace_id相关的Filter实现
消费端通过ConsumerTraceFilter已经将trace_id放到RpcContext里了,服务提供端要干的事就是从RpcContext中将 trace_id 取出来,并通过MDC放到本次执行线程中。
@Slf4j
@Activate(group = CommonConstants.PROVIDER, order = 1)
public class ProviderTraceFilter implements Filter {
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
RpcContext rpcContext = RpcContext.getContext();
String traceId = rpcContext.getAttachment(DubboConstant.TRACE_ID);
if(StringUtils.isNotBlank(traceId)) {
MDC.put(DubboConstant.TRACE_ID,traceId);
}
Result result = invoker.invoke(invocation);
// 因为线程可能会被复用,所以在一次请求结束后要移除该线程ThreadLocal中的trace_id
MDC.remove(DubboConstant.TRACE_ID);
return result;
}
}
将服务提供端的日志格式设置一下,打印出 trace_id
logging.pattern.console=%d{yyyy-MM-dd HH:mm:ss} %-5level [%thread] trace_id:[%X{trace_id}] %logger : %msg%n
日志相关的Filter实现
这个Filter实现的功能为,在收到RPC请求后,将本次请求的参数打印出来。在拿到service方法的返回结果后,打印本次service方法执行耗时及返回结果。
@Slf4j
@Activate(group = CommonConstants.PROVIDER, order = 2)
public class ProviderLogFilter implements Filter {
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
String host = invoker.getUrl().getHost();
int port = invoker.getUrl().getPort();
String serviceName = invocation.getTargetServiceUniqueName();
String methodName = invocation.getMethodName();
Object[] arguments = invocation.getArguments();
String traceId = RpcContext.getContext().getAttachment(DubboConstant.TRACE_ID);
log.info("[receive request] trace_id:{}, host:{}, port:{}, serviceName:{}, methodName:{}, arguments:{}", traceId, host, port, serviceName, methodName, arguments);
StopWatch stopWatch = new StopWatch();
stopWatch.start();
Result result = invoker.invoke(invocation);
stopWatch.stop();
long totalTimeMillis = stopWatch.getTotalTimeMillis();
log.info("[send response] trace_id:{}, elapsed time:{}ms, response:{}", traceId, totalTimeMillis, result.getValue().toString());
return result;
}
}
效果展示
启动provider服务,consumer通过测试类的形式启动服务并发起调用
测试类代码
@SpringBootTest
public class UserTest {
@DubboReference
IUserService userService;
@Test
public void userTest() {
UserInfoDTO userInfo = userService.getUserInfo(1);
System.out.println(JSON.toJSONString(userInfo));
}
}
测试方法成功执行完毕,日志展示
consumer端日志
2024-06-03 15:47:17.853 INFO 52493 --- [ main] c.hml.consumer.filter.ConsumerLogFilter : [send request] trace_id:41005892-cdd1-4f0c-af13-c7d3aef4cdf0, host:192.168.40.24, port:20880, serviceName:com.hml.api.user.IUserService, methodName:getUserInfo, arguments:[1]
2024-06-03 15:47:17.900 INFO 52493 --- [ main] c.hml.consumer.filter.ConsumerLogFilter : [receive response] trace_id:41005892-cdd1-4f0c-af13-c7d3aef4cdf0, elapsed time:46ms, response:UserInfoDTO(id=1, name=张三, roles=[RoleDTO(roleId=1, roleName=质检员), RoleDTO(roleId=2, roleName=初审员)])
{"id":1,"name":"张三","roles":[{"roleId":1,"roleName":"质检员"},{"roleId":2,"roleName":"初审员"}]}
由于consumer我没有设置日志格式,所以还是默认格式。
provider端日志
2024-06-03 15:47:17 INFO [DubboServerHandler-192.168.40.24:20880-thread-2] trace_id:[41005892-cdd1-4f0c-af13-c7d3aef4cdf0] com.hml.provider.filter.ProviderLogFilter : [receive request] trace_id:41005892-cdd1-4f0c-af13-c7d3aef4cdf0, host:192.168.40.24, port:20880, serviceName:com.hml.api.user.IUserService:0.0.0, methodName:getUserInfo, arguments:[1]
2024-06-03 15:47:17 INFO [DubboServerHandler-192.168.40.24:20880-thread-2] trace_id:[41005892-cdd1-4f0c-af13-c7d3aef4cdf0] com.hml.provider.user.UserServiceImpl : 进入到getUserInfo方法了
2024-06-03 15:47:17 INFO [DubboServerHandler-192.168.40.24:20880-thread-2] trace_id:[41005892-cdd1-4f0c-af13-c7d3aef4cdf0] com.hml.provider.filter.ProviderLogFilter : [send response] trace_id:41005892-cdd1-4f0c-af13-c7d3aef4cdf0, elapsed time:1ms, response:UserInfoDTO(id=1, name=张三, roles=[RoleDTO(roleId=1, roleName=质检员), RoleDTO(roleId=2, roleName=初审员)])
可以看到,trace_id 的传递机制已经实现,consumer与provider的请求、返回 日志也打印出来了,本次编码目标-实现。