文章目录

  • 一、现象
  • 二、问题排查
  • 三、结论
  • 四、解决方案


一、现象

使用 nacos 作注册中心的线上 dubbo 消费端应用每隔 1 分钟就会抛出以下异常(为使描述简单化,文章中使用本地 demo 来复现),该异常表示无法连接到 172.17.0.1:20881 这台提供端

21:11:49.843 [dubbo-client-idleCheck-thread-1] ERROR org.apache.dubbo.remoting.exchange.support.header.ReconnectTimerTask.doTask(51) -  [DUBBO] Fail to connect to HeaderExchangeClient [channel=org.apache.dubbo.remoting.transport.netty4.NettyClient [172.17.0.1:0 -> /172.17.0.1:20881]], dubbo version: 2.7.3, current host: 172.17.0.1
org.apache.dubbo.remoting.RemotingException: client(url: dubbo://172.17.0.1:20881/com.example.dubbo.HelloService?anyhost=true&application=dubbo-consumer-app&bean.name=com.example.dubbo.HelloService&category=providers&check=false&codec=dubbo&deprecated=false&dubbo=2.0.2&dynamic=true&generic=false&heartbeat=60000&interface=com.example.dubbo.HelloService&lazy=false&methods=sayHello&path=com.example.dubbo.HelloService&pid=56029&protocol=dubbo®ister=true®ister.ip=172.17.0.1&release=2.7.3&remote.application=dubbo-provider-app&server=netty4&side=consumer&sticky=false×tamp=1683113373687) failed to connect to server /172.17.0.1:20881, error message is:拒绝连接: /172.17.0.1:20881
	at org.apache.dubbo.remoting.transport.netty4.NettyClient.doConnect(NettyClient.java:166)
	at org.apache.dubbo.remoting.transport.AbstractClient.connect(AbstractClient.java:190)
	at org.apache.dubbo.remoting.transport.AbstractClient.reconnect(AbstractClient.java:246)
	at org.apache.dubbo.remoting.exchange.support.header.HeaderExchangeClient.reconnect(HeaderExchangeClient.java:155)
	at org.apache.dubbo.remoting.exchange.support.header.ReconnectTimerTask.doTask(ReconnectTimerTask.java:49)
	at org.apache.dubbo.remoting.exchange.support.header.AbstractTimerTask.run(AbstractTimerTask.java:87)
	at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:648)
	at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:727)
	at org.apache.dubbo.common.timer.HashedWheelTimer$Worker.run(HashedWheelTimer.java:449)
	at java.lang.Thread.run(Thread.java:748)
Caused by: io.netty.channel.AbstractChannel$AnnotatedConnectException: 拒绝连接: /172.17.0.1:20881
	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
	at io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:325)
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:340)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:635)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:582)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:499)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:461)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	... 1 more
Caused by: java.net.ConnectException: 拒绝连接
	... 11 more

二、问题排查

经过确认,172.17.0.1:20881 这台提供端确实已经下线,所以才会无法连接。

通过查询 dubbo 源码得知,ReconnectTimerTask 是一个定时任务,其实例被 DubboInvoker 实例持有,当 DubboInvoker 对应的消费端服务与对端的提供端服务断开连接时,该定时任务就会定时重连提供端。正常情况下不会出现这种异常,因为提供端下线以后,会通过注册中心通知到消费端,消费端对应的 DubboInvoker 实例会被销毁,从而重连定时任务也会被销毁。

找到出问题的 HelloService 在应用中的使用方式,发现既有通过 @Reference 注解的方式使用,又有通过 xml 配置的方式使用。首先,将 arthas 连接到出问题的消费端应用,然后执行以下命令

ognl '#context=@org.apache.dubbo.config.spring.extension.SpringExtensionFactory@CONTEXTS.iterator.next, #context.getBean("helloService").handler.invoker.directory.urlInvokerMap'

得到结果为

dubbo 注解方式配置方法配置超时时间_apache

发现 HelloService 服务的 RegistryDirectory 实例中确实还存在已经下线的提供端,说明提供端下线后该消费端没有感知到

接着,使用 arthas 监控看看消费端的服务监听 notify 方法是否生效,运行以下命令

watch org.apache.dubbo.registry.support.FailbackRegistry notify params

然后,将 20880 那台服务提供端也下线,看看 watch 命令的输出,如下所示

dubbo 注解方式配置方法配置超时时间_java_02

说明服务下线通知功能是正常的,不过这里的 RegistryDirectory 实例和上面使用 ognl 表达式查询的 RegistryDirectory 实例不是同一个,使用 ognl 表达式查询的实例如下

dubbo 注解方式配置方法配置超时时间_apache_03

说明 HelloService 服务被 refer 了两次,也就是生成了两个服务引用,但是只有一个引用的服务监听生效。

三、结论

联系到 HelloService 在应用中有注解和 xml 两种引用方式,调试一遍服务引用的创建过程,发现在 NacosRegistry 中有这么一段服务订阅代码

dubbo 注解方式配置方法配置超时时间_java_04

这段代码的意思是,当相同的服务引用被创建了两次,只有第一次创建的引用会订阅服务。所以通过注解和 xml 两种方式创建 HelloService 服务引用时,会导致其中一个引用不会订阅服务变更,导致无法感知提供端下线,就会出现不断重连提供端的现象。

四、解决方案

应用中应当禁止同时使用注解和 xml 的方式来引用 dubbo 服务。