Description
We use ODL netconf topology. It failed to establish connection to Netconf server because of folowing error.
AbstractNetconfSessionNegotiator - Failed to send message <hello xmlns="urn:ietf:params:xml:ns:netconf:base:1.0"> <capabilities> <capability>urn:ietf:params:netconf:capability:exi:1.0</capability> <capability>urn:ietf:params:netconf:base:1.1</capability> <capability>urn:ietf:params:netconf:base:1.0</capability> </capabilities> </hello> java.lang.IllegalStateException: Channel closed at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandlerWriter.write(AsyncSshHandlerWriter.java:64) ~[netconf-netty-util-1.13.4.jar:?] at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler.write(AsyncSshHandler.java:188) ~[netconf-netty-util-1.13.4.jar:?]
Then logs were flooded with exceptions:
[WARN ] 2021-11-09 17:09:36.562 [nioEventLoopGroup-3-1] AbstractChannelHandlerContext - An exception 'java.lang.IllegalStateException: complete already: NetconfSessionPromise@546106c5(failure: java.lang.IllegalStateException: Channel closed)' [enable DEBUG level for full stacktrace] was thrown by a user handler's exceptionCaught() method while handling the following exception: java.lang.IllegalStateException: complete already: NetconfSessionPromise@546106c5(failure: java.lang.IllegalStateException: Channel closed) at io.netty.util.concurrent.DefaultPromise.setFailure(DefaultPromise.java:112) ~[netty-common-4.1.65.Final.jar:4.1.65.Final] at org.opendaylight.netconf.nettyutil.AbstractNetconfSessionNegotiator.negotiationFailed(AbstractNetconfSessionNegotiator.java:290) ~[netconf-netty-util-1.13.4.jar:?] at org.opendaylight.netconf.nettyutil.AbstractNetconfSessionNegotiator.channelRead(AbstractNetconfSessionNegotiator.java:330) ~[netconf-netty-util-1.13.4.jar:?] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.65.Final.jar:4.1.65.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.65.Final.jar:4.1.65.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [netty-transport-4.1.65.Final.jar:4.1.65.Final] at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324) [netty-codec-4.1.65.Final.jar:4.1.65.Final] at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296) [netty-codec-4.1.65.Final.jar:4.1.65.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.65.Final.jar:4.1.65.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.65.Final.jar:4.1.65.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [netty-transport-4.1.65.Final.jar:4.1.65.Final] at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324) [netty-codec-4.1.65.Final.jar:4.1.65.Final] at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296) [netty-codec-4.1.65.Final.jar:4.1.65.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.65.Final.jar:4.1.65.Final] at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:61) [netty-transport-4.1.65.Final.jar:4.1.65.Final] at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:370) [netty-transport-4.1.65.Final.jar:4.1.65.Final] at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [netty-common-4.1.65.Final.jar:4.1.65.Final] at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) [netty-common-4.1.65.Final.jar:4.1.65.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) [netty-transport-4.1.65.Final.jar:4.1.65.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.65.Final.jar:4.1.65.Final] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.65.Final.jar:4.1.65.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.65.Final.jar:4.1.65.Final] at java.lang.Thread.run(Thread.java:829) [?:?] Caused by: java.lang.IllegalStateException: complete already: NetconfSessionPromise@546106c5(failure: java.lang.IllegalStateException: Channel closed) at io.netty.util.concurrent.DefaultPromise.setSuccess(DefaultPromise.java:99) ~[netty-common-4.1.65.Final.jar:4.1.65.Final] at org.opendaylight.netconf.nettyutil.NetconfSessionPromise.setSuccess(NetconfSessionPromise.java:79) ~[netconf-netty-util-1.13.4.jar:?] at org.opendaylight.netconf.nettyutil.NetconfSessionPromise.setSuccess(NetconfSessionPromise.java:27) ~[netconf-netty-util-1.13.4.jar:?] at org.opendaylight.netconf.nettyutil.AbstractNetconfSessionNegotiator.negotiationSuccessful(AbstractNetconfSessionNegotiator.java:284) ~[netconf-netty-util-1.13.4.jar:?] at org.opendaylight.netconf.client.NetconfClientSessionNegotiator.handleMessage(NetconfClientSessionNegotiator.java:93) ~[netconf-client-1.13.4.jar:?] at org.opendaylight.netconf.nettyutil.AbstractNetconfSessionNegotiator.channelRead(AbstractNetconfSessionNegotiator.java:327) ~[netconf-netty-util-1.13.4.jar:?] ... 20 more Nov 09, 2021 5:09:36 PM com.google.common.util.concurrent.AbstractFuture executeListener SEVERE: RuntimeException while executing runnable CallbackListener{org.opendaylight.netconf.sal.connect.netconf.NetconfDevice$1@7230cd8c} with executor MoreExecutors.directExecutor() java.lang.IllegalStateException: Already initialized at com.google.common.base.Preconditions.checkState(Preconditions.java:508) at org.opendaylight.netconf.sal.connect.netconf.sal.NetconfDeviceSalProvider$MountInstance.onTopologyDeviceConnected(NetconfDeviceSalProvider.java:127) at org.opendaylight.netconf.sal.connect.netconf.sal.NetconfDeviceSalFacade.onDeviceConnected(NetconfDeviceSalFacade.java:87) at org.opendaylight.netconf.sal.connect.netconf.sal.NetconfDeviceSalFacade.onDeviceConnected(NetconfDeviceSalFacade.java:43) at org.opendaylight.netconf.sal.connect.netconf.NetconfDevice.handleSalInitializationSuccess(NetconfDevice.java:262) at org.opendaylight.netconf.sal.connect.netconf.NetconfDevice$1.onSuccess(NetconfDevice.java:184) at org.opendaylight.netconf.sal.connect.netconf.NetconfDevice$1.onSuccess(NetconfDevice.java:181) at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1089) at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30) at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1174) at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:969) at com.google.common.util.concurrent.AbstractFuture.setFuture(AbstractFuture.java:800) at com.google.common.util.concurrent.AbstractTransformFuture$AsyncTransformFuture.setResult(AbstractTransformFuture.java:224) at com.google.common.util.concurrent.AbstractTransformFuture$AsyncTransformFuture.setResult(AbstractTransformFuture.java:202) at com.google.common.util.concurrent.AbstractTransformFuture.run(AbstractTransformFuture.java:163) at com.google.common.util.concurrent.MoreExecutors$5$1.run(MoreExecutors.java:1091) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:829)
It wasn't possible to make netconf connect again with deleting and creating mount point again.
We checked, that netconf server is running and we were able to send netconf RPCs via ssh.
Attachments
Issue Links
- duplicates
-
NETCONF-784 ReconnectPromise keep reconnecting after device unregistered
-
- Resolved
-
# | Subject | Branch | Project | Status | CR | V |
---|---|---|---|---|---|---|
98467,2 | WIP: Do not set success/fail on terminated promise | master | netconf | Status: ABANDONED | 0 | -1 |
98533,1 | WIP: Test device reconnection after failure | master | netconf | Status: ABANDONED | 0 | +1 |