Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

升级到3.2.9后，启动Consumer有时会打印一个异常堆栈（Triple协议） #13415

Closed
ldcsaa opened this issue Nov 27, 2023 · 1 comment
Closed

升级到3.2.9后，启动Consumer有时会打印一个异常堆栈（Triple协议） #13415

ldcsaa opened this issue Nov 27, 2023 · 1 comment
Labels
type/bug Bugs to being fixed

Comments

@ldcsaa
Copy link

ldcsaa commented Nov 27, 2023 •
edited

Dubbo consumer 与 provider 之间以 Triple 协议连接。有些Consumer启动时会打印一个异常堆栈。
注：3.2.7 版本不会报错，3.2.9 版本换成 dubbo 协议也不会报错。

consumer dubbo 配置：

# dubbo
dubbo.protocols:
  #dubbo:
  #  name: dubbo
  #  port: 5006
  tri:
    name: tri
    port: 6006

consumer 日志

2023-11-27 15:28:17.566 INFO  [nacos.publisher-com.alibaba.nacos.client.naming.event.InstancesChangeEvent] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] Received instance notification, serviceName: hp-demo-infra-basic-service, instances: 1, dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:17.574 INFO  [nacos.publisher-com.alibaba.nacos.client.naming.event.InstancesChangeEvent] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] Dynamically registering consumer model hp-demo-infra-basic-service/org.apache.dubbo.metadata.MetadataService:1.0.0 into model Dubbo Module[1.1.0], dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:17.710 INFO  [NettyClientWorker-4-1] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] The connection of /192.168.56.1:51328 -> /192.168.56.1:6002 is established., dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:17.714 INFO  [nacos.publisher-com.alibaba.nacos.client.naming.event.InstancesChangeEvent] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] Successfully connect to server /192.168.56.1:6002 from NettyConnectionClient 192.168.56.1 using dubbo version 3.2.9, channel is NettyChannel [channel=[id: 0xd0f34385, L:/192.168.56.1:51328 - R:/192.168.56.1:6002]], dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:17.725 INFO  [nacos.publisher-com.alibaba.nacos.client.naming.event.InstancesChangeEvent] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] Start NettyConnectionClient /192.168.56.1 connect to the server /192.168.56.1:6002, dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:17.971 INFO  [nacos.publisher-com.alibaba.nacos.client.naming.event.InstancesChangeEvent] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] Close netty channel [id: 0xd0f34385, L:/192.168.56.1:51328 - R:/192.168.56.1:6002], dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:17.979 INFO  [nacos.publisher-com.alibaba.nacos.client.naming.event.InstancesChangeEvent] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] 1 unique working revisions: 8bbb8b8b54212663c66ab1934a385a68 , dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:17.980 WARN  [NettyClientWorker-4-1] i.n.u.concurrent.DefaultPromise#notifyListener0(L:593) -> An exception was thrown by org.apache.dubbo.remoting.transport.netty4.NettyConnectionClient$1$$Lambda$1920/0x000000080174b260.operationComplete() java.lang.IllegalStateException: complete already: DefaultPromise@1920751f(success)
	at io.netty.util.concurrent.DefaultPromise.setSuccess(DefaultPromise.java:100) ~[netty-common-4.1.101.Final.jar:4.1.101.Final]
	at org.apache.dubbo.remoting.transport.netty4.NettyConnectionClient.doClose(NettyConnectionClient.java:153) ~[dubbo-3.2.9.jar:3.2.9]
	at org.apache.dubbo.remoting.transport.netty4.NettyConnectionClient$1.lambda$initChannel$0(NettyConnectionClient.java:134) ~[dubbo-3.2.9.jar:3.2.9]
	at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:590) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:557) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:492) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:636) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.DefaultPromise.setSuccess0(DefaultPromise.java:625) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:105) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.DefaultChannelPromise.trySuccess(DefaultChannelPromise.java:84) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.AbstractChannel$CloseFuture.setClosed(AbstractChannel.java:1164) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe.doClose0(AbstractChannel.java:755) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:731) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:620) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.DefaultChannelPipeline$HeadContext.close(DefaultChannelPipeline.java:1352) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:749) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:727) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	... suppressed 3 lines
	at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:590) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:557) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:492) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.DefaultPromise.addListener(DefaultPromise.java:185) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.DefaultChannelPromise.addListener(DefaultChannelPromise.java:95) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.DefaultChannelPromise.addListener(DefaultChannelPromise.java:30) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	... suppressed 2 lines
	at io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:753) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.AbstractChannelHandlerContext.access$1200(AbstractChannelHandlerContext.java:61) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.AbstractChannelHandlerContext$11.run(AbstractChannelHandlerContext.java:732) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569) [netty-transport-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.101.Final.jar:4.1.101.Final]
	at java.base/java.lang.Thread.run(Thread.java:833) [?:?]

2023-11-27 15:28:17.991 INFO  [nacos.publisher-com.alibaba.nacos.client.naming.event.InstancesChangeEvent] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] Notify service io.github.hpsocket.demo.infra.basic.service.DemoService:null with urls 1, dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:18.004 INFO  [NettyClientWorker-4-1] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] The client has been closed and will not reconnect. , dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:18.005 INFO  [NettyClientWorker-4-2] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] The connection of /192.168.56.1:51329 -> /192.168.56.1:6002 is established., dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:18.005 INFO  [nacos.publisher-com.alibaba.nacos.client.naming.event.InstancesChangeEvent] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] Successfully connect to server /192.168.56.1:6002 from NettyConnectionClient 192.168.56.1 using dubbo version 3.2.9, channel is NettyChannel [channel=[id: 0xcedd1bc3, L:/192.168.56.1:51329 - R:/192.168.56.1:6002]], dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:18.031 INFO  [nacos.publisher-com.alibaba.nacos.client.naming.event.InstancesChangeEvent] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] Start NettyConnectionClient /192.168.56.1 connect to the server /192.168.56.1:6002, dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:18.080 INFO  [nacos.publisher-com.alibaba.nacos.client.naming.event.InstancesChangeEvent] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] Refreshed invoker size 1 from registry ServiceDiscoveryRegistryDirectory(registry: 192.168.56.23:8848, subscribed key: [hp-demo-infra-basic-service])-Directory(invokers: 0[], validInvokers: 0[], invokersToReconnect: 0[]), dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:18.130 INFO  [nacos.publisher-com.alibaba.nacos.client.naming.event.InstancesChangeEvent] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] No interface address available, stop compare., dubbo version: 3.2.9, current host: 192.168.56.1
2023-11-27 15:28:18.136 INFO  [nacos.publisher-com.alibaba.nacos.client.naming.event.InstancesChangeEvent] o.a.d.common.logger.log4j2.Log4j2Logger#info(L:61) ->  [DUBBO] Received invokers changed event from registry. Registry type: instance. Service Key: io.github.hpsocket.demo.infra.basic.service.DemoService. Urls Size : 1. Invokers Size : 1. Available Size: 1. Available Invokers : 192.168.56.1:6002, dubbo version: 3.2.9, current host: 192.168.56.1

Environment

  • Dubbo version: 3.2.9
  • Operating System version: win10
  • Java version: jdk17

Steps to reproduce this issue

  1. 启动 dubbo provider
  2. 启动 dubbo consumer（有些Consumer启动时会打印一个异常堆栈）
  3. 不做任何操作

Expected Behavior

不报错

Actual Behavior

报错
@ldcsaa ldcsaa added the type/bug Bugs to being fixed label Nov 27, 2023
@ldcsaa ldcsaa changed the title 升级到3.2.9后，启动Consumer会打印一个异常堆栈（Triple协议） 升级到3.2.9后，启动Consumer有时会打印一个异常堆栈 Nov 27, 2023
@ldcsaa ldcsaa changed the title 升级到3.2.9后，启动Consumer有时会打印一个异常堆栈 升级到3.2.9后，启动Consumer有时会打印一个异常堆栈（Triple协议） Nov 27, 2023
@AlbumenJ
Copy link
Member

Same with #13398, track in #13398

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
type/bug Bugs to being fixed
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@ldcsaa @AlbumenJ