Uploaded image for project: 'netconf'
  1. netconf
  2. NETCONF-1078

Unexpected exception from NetconfSessionPromise after negotiation failure

    XMLWordPrintable

Details

    • Bug
    • Status: In Progress
    • Medium
    • Resolution: Unresolved
    • 6.0.0
    • None
    • netconf
    • None

    Description

      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
      

      Attachments

        # Subject Branch Project Status CR V

        Activity

          People

            sangwookha Sangwook Ha
            sangwookha Sangwook Ha
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated: