-
Bug
-
Resolution: Unresolved
-
Medium
-
None
-
6.0.0
-
None
When NETCONF session negotiation fails and AbstractNetconfSessionNegotiator.negotiationFailed() is called, the state of NetconfSessionPromise associated with the negotiation changes to 'failure'.
In that case a second attempt to set failure in NetconfSessionPromise.channelConnectComplete() always fails and triggers an unexpected exception.
For example, the following log shows that NETCONF negotiation failed because of an ill-formed hello message:
07:16:01.996 INFO [globalWorkerGroup-3-2] Unexpected error during negotiation on channel [id: 0x165e725d] io.netty.handler.codec.DecoderException: org.xml.sax.SAXParseException; lineNumber: 28; columnNumber: 3; The element type "nc:rpc-reply" must be terminated by the matching end-tag "</nc:rpc-reply>". at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:499) ~[bundleFile:4.1.94.Final] at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:290) ~[bundleFile:4.1.94.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[bundleFile:4.1.94.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[bundleFile:4.1.94.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[bundleFile:4.1.94.Final] at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346) ~[bundleFile:4.1.94.Final] at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:333) ~[bundleFile:4.1.94.Final] at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:454) ~[bundleFile:4.1.94.Final] at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:290) ~[bundleFile:4.1.94.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[bundleFile:4.1.94.Final] at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:61) ~[bundleFile:4.1.94.Final] at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:425) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470) ~[bundleFile:4.1.94.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) ~[bundleFile:4.1.94.Final] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[bundleFile:4.1.94.Final] at java.lang.Thread.run(Thread.java:833) ~[?:?] Caused by: org.xml.sax.SAXParseException: The element type "nc:rpc-reply" must be terminated by the matching end-tag "</nc:rpc-reply>". at com.sun.org.apache.xerces.internal.parsers.DOMParser.parse(DOMParser.java:262) ~[?:?] at com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderImpl.parse(DocumentBuilderImpl.java:342) ~[?:?] at javax.xml.parsers.DocumentBuilder.parse(DocumentBuilder.java:122) ~[?:?] at org.opendaylight.netconf.api.xml.XmlUtil.readXmlToDocument(XmlUtil.java:123) ~[bundleFile:?] at org.opendaylight.netconf.nettyutil.handler.NetconfXMLToHelloMessageDecoder.decode(NetconfXMLToHelloMessageDecoder.java:91) ~[bundleFile:?] at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:529) ~[bundleFile:4.1.94.Final] at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:468) ~[bundleFile:4.1.94.Final] ... 19 more
And another exception was thrown from NetconfSessionPromise because it was calling setFailure() again:
07:16:02.017 WARN [globalWorkerGroup-3-2] An exception was thrown by org.opendaylight.netconf.nettyutil.NetconfSessionPromise$$Lambda$2678/0x00000001013c2d68.operationComplete() java.lang.IllegalStateException: complete already: NetconfSessionPromise@6c53568b(failure: io.netty.handler.codec.DecoderException: org.xml.sax.SAXParseException; lineNumber: 28; columnNumber: 3; The element type "nc:rpc-reply" must be terminated by the matching end-tag "</nc:rpc-reply>".) at io.netty.util.concurrent.DefaultPromise.setFailure(DefaultPromise.java:113) ~[bundleFile:4.1.94.Final] at org.opendaylight.netconf.nettyutil.NetconfSessionPromise.channelConnectComplete(NetconfSessionPromise.java:102) ~[bundleFile:?] at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:590) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:583) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:559) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:492) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:636) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.DefaultPromise.setFailure0(DefaultPromise.java:629) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.DefaultPromise.setFailure(DefaultPromise.java:110) ~[bundleFile:4.1.94.Final] at io.netty.channel.DefaultChannelPromise.setFailure(DefaultChannelPromise.java:89) ~[bundleFile:4.1.94.Final] at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler.safelyDisconnect(AsyncSshHandler.java:282) ~[bundleFile:?] at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler.lambda$disconnect$6(AsyncSshHandler.java:257) ~[bundleFile:?] at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470) ~[bundleFile:4.1.94.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) ~[bundleFile:4.1.94.Final] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[bundleFile:4.1.94.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[bundleFile:4.1.94.Final] at java.lang.Thread.run(Thread.java:833) ~[?:?] Caused by: java.lang.IllegalStateException: Negotiation failed