zrlw edited a comment on issue #8689: URL: https://github.com/apache/dubbo/issues/8689#issuecomment-914050302
找到另外一处慢的地方（DubboBootstrapMultiInstanceTest） 23:18分开始org.apache.dubbo.remoting.transport.netty4.NettyClient.doConnect(NettyClient.java:171) ``` 2021-09-06T23:18:01.6130806Z org.apache.dubbo.remoting.RemotingException: client(url: dubbo://10.1.0.234:2001/org.apache.dubbo.metadata.MetadataService?codec=dubbo&connect.lazy.initial.state=true&dubbo=2.0.2&group=provider-app&heartbeat=60000&port=2001&protocol=dubbo&release=3.0.3-SNAPSHOT&send.reconnect=true&side=consumer&timeout=5000&version=1.0.0) failed to connect to server /10.1.0.234:2001, error message is:Connection refused: no further information: /10.1.0.234:2001 2021-09-06T23:18:01.6140508Z at org.apache.dubbo.remoting.transport.netty4.NettyClient.doConnect(NettyClient.java:171) 2021-09-06T23:18:01.6143201Z at org.apache.dubbo.remoting.transport.AbstractClient.connect(AbstractClient.java:202) 2021-09-06T23:18:01.6145717Z at org.apache.dubbo.remoting.transport.AbstractClient.reconnect(AbstractClient.java:258) 2021-09-06T23:18:01.6155334Z at org.apache.dubbo.remoting.exchange.support.header.HeaderExchangeClient.reconnect(HeaderExchangeClient.java:166) 2021-09-06T23:18:01.6164494Z at org.apache.dubbo.remoting.exchange.support.header.ReconnectTimerTask.doTask(ReconnectTimerTask.java:49) 2021-09-06T23:18:01.6167756Z at org.apache.dubbo.remoting.exchange.support.header.AbstractTimerTask.run(AbstractTimerTask.java:87) 2021-09-06T23:18:01.6170356Z at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:648) 2021-09-06T23:18:01.6172596Z at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:727) 2021-09-06T23:18:01.6174716Z at org.apache.dubbo.common.timer.HashedWheelTimer$Worker.run(HashedWheelTimer.java:449) 2021-09-06T23:18:01.6175998Z at java.base/java.lang.Thread.run(Thread.java:829) 2021-09-06T23:18:01.6177247Z Caused by: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: no further information: /10.1.0.234:2001 2021-09-06T23:18:01.6178649Z Caused by: java.net.ConnectException: Connection refused: no further information 2021-09-06T23:18:01.6179878Z at java.base/sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) 2021-09-06T23:18:01.6181385Z at java.base/sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:777) 2021-09-06T23:18:01.6183388Z at io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:330) 2021-09-06T23:18:01.6185632Z at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:334) 2021-09-06T23:18:01.6187597Z at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:707) 2021-09-06T23:18:01.6189735Z at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655) 2021-09-06T23:18:01.6191923Z at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581) 2021-09-06T23:18:01.6193307Z at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) 2021-09-06T23:18:01.6194818Z at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) 2021-09-06T23:18:01.6196422Z at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) 2021-09-06T23:18:01.6198282Z at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) 2021-09-06T23:18:01.6199537Z at java.base/java.lang.Thread.run(Thread.java:829) ``` 日志显示HashedWheelTimer的worker线程一直调用expireTimeouts方法到了23:34分，持续调用了16分钟： ``` 2021-09-06T23:34:33.6234093Z org.apache.dubbo.remoting.RemotingException: client(url: dubbo://10.1.0.234:2001/org.apache.dubbo.metadata.MetadataService?codec=dubbo&connect.lazy.initial.state=true&dubbo=2.0.2&group=provider-app&heartbeat=60000&port=2001&protocol=dubbo&release=3.0.3-SNAPSHOT&send.reconnect=true&side=consumer&timeout=5000&version=1.0.0) failed to connect to server /10.1.0.234:2001, error message is:Connection refused: no further information: /10.1.0.234:2001 2021-09-06T23:34:33.6238443Z at org.apache.dubbo.remoting.transport.netty4.NettyClient.doConnect(NettyClient.java:171) 2021-09-06T23:34:33.6241063Z at org.apache.dubbo.remoting.transport.AbstractClient.connect(AbstractClient.java:202) 2021-09-06T23:34:33.6245115Z at org.apache.dubbo.remoting.transport.AbstractClient.reconnect(AbstractClient.java:258) 2021-09-06T23:34:33.6248407Z at org.apache.dubbo.remoting.exchange.support.header.HeaderExchangeClient.reconnect(HeaderExchangeClient.java:166) 2021-09-06T23:34:33.6252119Z at org.apache.dubbo.remoting.exchange.support.header.ReconnectTimerTask.doTask(ReconnectTimerTask.java:49) 2021-09-06T23:34:33.6255676Z at org.apache.dubbo.remoting.exchange.support.header.AbstractTimerTask.run(AbstractTimerTask.java:87) 2021-09-06T23:34:33.6259548Z at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:648) 2021-09-06T23:34:33.6265744Z at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:727) 2021-09-06T23:34:33.6267624Z at org.apache.dubbo.common.timer.HashedWheelTimer$Worker.run(HashedWheelTimer.java:449) 2021-09-06T23:34:33.6268785Z at java.base/java.lang.Thread.run(Thread.java:829) 2021-09-06T23:34:33.6269927Z Caused by: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: no further information: /10.1.0.234:2001 2021-09-06T23:34:33.6271355Z Caused by: java.net.ConnectException: Connection refused: no further information 2021-09-06T23:34:33.6272490Z at java.base/sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) 2021-09-06T23:34:33.6273861Z at java.base/sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:777) 2021-09-06T23:34:33.6275648Z at io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:330) 2021-09-06T23:34:33.6277619Z at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:334) 2021-09-06T23:34:33.6279377Z at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:707) 2021-09-06T23:34:33.6281298Z at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655) 2021-09-06T23:34:33.6283215Z at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581) 2021-09-06T23:34:33.6284730Z at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) 2021-09-06T23:34:33.6286294Z at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) 2021-09-06T23:34:33.6287930Z at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) 2021-09-06T23:34:33.6289575Z at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) 2021-09-06T23:34:33.6290896Z at java.base/java.lang.Thread.run(Thread.java:829) ``` reconnectTimerTask一直运行了16分钟没有被cancel的原因应该是providerBootstrap.start()抛了异常： ``` 2021-09-06T23:17:04.6300294Z [06/09/21 23:17:04:530 UTC] main ERROR config.ServiceConfig: [DUBBO] Failed register interface application mapping for service org.apache.dubbo.config.api.DemoService:2.0, dubbo version: 3.0.3-SNAPSHOT, current host: 10.1.0.234 2021-09-06T23:17:04.6301602Z java.lang.RuntimeException 2021-09-06T23:17:04.6303393Z at org.apache.dubbo.registry.client.metadata.MetadataServiceNameMapping.map(MetadataServiceNameMapping.java:88) 2021-09-06T23:17:04.6306097Z at org.apache.dubbo.config.ServiceConfig.lambda$exported$1(ServiceConfig.java:270) 2021-09-06T23:17:04.6307317Z at java.base/java.util.ArrayList.forEach(ArrayList.java:1541) 2021-09-06T23:17:04.6308654Z at org.apache.dubbo.config.ServiceConfig.exported(ServiceConfig.java:266) 2021-09-06T23:17:04.6310056Z at org.apache.dubbo.config.ServiceConfig.doExport(ServiceConfig.java:371) 2021-09-06T23:17:04.6311444Z at org.apache.dubbo.config.ServiceConfig.export(ServiceConfig.java:244) 2021-09-06T23:17:04.6318288Z at org.apache.dubbo.config.bootstrap.DubboBootstrap.exportServices(DubboBootstrap.java:1476) 2021-09-06T23:17:04.6320287Z at org.apache.dubbo.config.bootstrap.DubboBootstrap.doStart(DubboBootstrap.java:1190) 2021-09-06T23:17:04.6322235Z at org.apache.dubbo.config.bootstrap.DubboBootstrap.start(DubboBootstrap.java:1166) 2021-09-06T23:17:04.6325718Z at org.apache.dubbo.config.bootstrap.DubboBootstrapMultiInstanceTest.testMultiModuleApplication(DubboBootstrapMultiInstanceTest.java:200) ``` 然后这个RuntimeException被finally捕获后又去做providerBootstrap.destroy()，这个destroy应该没有考虑这种场景（可能需要单开issue了）。 PS： DubboBootstrapMultiInstanceTest这个测试类缺少断言，加了断言可能就不会过，比如testMultiModuleApplication这个方法，调用sayName实际是 org.apache.dubbo.remoting.RemotingException: Not found exported service: provider-app/org.apache.dubbo.metadata.MetadataService:1.0.0:2002 in [], may be version or group mismatch -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: notifications-unsubscr...@dubbo.apache.org For queries about this service, please contact Infrastructure at: us...@infra.apache.org --------------------------------------------------------------------- To unsubscribe, e-mail: notifications-unsubscr...@dubbo.apache.org For additional commands, e-mail: notifications-h...@dubbo.apache.org
