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 |