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

NETCONF mount fails during reconnect

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Medium Medium
    • 2.0.13, 1.13.8
    • 2.0.4, 2.0.11
    • netconf
    • None

      This feature was working in silicon-sr1.

      How to reproduce:

        * mount device with TLS

      PUT /rests/data/network-topology:network-topology/topology=topology-netconf/node=tlstest 
      <node xmlns="urn:TBD:params:xml:ns:yang:network-topology">
        <node-id>tlstest</node-id>
        <key-based xmlns="urn:opendaylight:netconf-node-topology">
          <key-id xmlns="urn:opendaylight:netconf-node-topology">ODL_private_key_0</key-id>
          <username xmlns="urn:opendaylight:netconf-node-topology">netconf</username>
        </key-based>
        <host xmlns="urn:opendaylight:netconf-node-topology">10.20.35.147</host>
        <port xmlns="urn:opendaylight:netconf-node-topology">31500</port>
        <tcp-only xmlns="urn:opendaylight:netconf-node-topology">false</tcp-only>
        <protocol xmlns="urn:opendaylight:netconf-node-topology">
          <name xmlns="urn:opendaylight:netconf-node-topology">TLS</name>
        </protocol>
        <max-connection-attempts xmlns="urn:opendaylight:netconf-node-topology">2</max-connection-attempts>
      </node>
      

        * wait for connected state... will never happen

      GET /rests/data/network-topology:network-topology/topology=topology-netconf 
      { 
        "network-topology:topology": [ 
          { "topology-id": "topology-netconf", "node": [ 
            { 
              "node-id": "tlstest", 
              "netconf-node-topology:connection-status": "unable-to-connect",
              "netconf-node-topology:connected-message": "Maximum reconnection attempts reached", 
              "netconf-node-topology:max-connection-attempts": 2, 
              "netconf-node-topology:key-based": 
              { 
                "username": "netconf", 
                "key-id": "ODL_private_key_0" 
              }, 
              "netconf-node-topology:host": "10.20.35.147", 
              "netconf-node-topology:port": 31500, 
              "netconf-node-topology:protocol": { 
                "name": "TLS" 
              }, 
              "netconf-node-topology:tcp-only": false 
            } ] 
          } ] 
      }
      

      The following exception is thrown in karaf.log

      2022-01-26T08:21:54,819 | WARN  | globalWorkerGroup-3-5 | DefaultPromise                   | 66 - io.netty.common - 4.1.69.Final | An exception was thrown by org.opendaylight.netconf.nettyutil.AbstractNetconfSessionNegotiator$$Lambda$2453/0x00000007c1aae440.operationComplete()2022-01-26T08:21:54,819 | WARN  | globalWorkerGroup-3-5 | DefaultPromise                   | 66 - io.netty.common - 4.1.69.Final | An exception was thrown by org.opendaylight.netconf.nettyutil.AbstractNetconfSessionNegotiator$$Lambda$2453/0x00000007c1aae440.operationComplete()java.lang.IllegalStateException: Ssl handshake was not successful at com.google.common.base.Preconditions.checkState(Preconditions.java:510) ~[bundleFile:?] at org.opendaylight.netconf.nettyutil.AbstractNetconfSessionNegotiator.lambda$startNegotiation$0(AbstractNetconfSessionNegotiator.java:89) ~[bundleFile:?] at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:578) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:571) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:550) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:491) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:616) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.DefaultPromise.setFailure0(DefaultPromise.java:609) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.DefaultPromise.tryFailure(DefaultPromise.java:117) [bundleFile:4.1.69.Final] at io.netty.handler.ssl.SslHandler$7.run(SslHandler.java:2114) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) [bundleFile:4.1.69.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) [bundleFile:4.1.69.Final] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [bundleFile:4.1.69.Final] at java.lang.Thread.run(Unknown Source) [?:?]2022-01-26T08:21:54,823 | WARN  | globalWorkerGroup-3-6 | ChannelInitializer               | 66 - io.netty.common - 4.1.69.Final | Failed to initialize a channel. Closing: [id: 0x05f0242e]io.netty.channel.ChannelPipelineException: org.opendaylight.netconf.nettyutil.ReconnectPromise$1 is not a @Sharable handler, so can't be added or removed multiple times. at io.netty.channel.DefaultChannelPipeline.checkMultiplicity(DefaultChannelPipeline.java:600) ~[bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:202) ~[bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:381) ~[bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:370) ~[bundleFile:4.1.69.Final] at org.opendaylight.netconf.nettyutil.ReconnectPromise.lambda$lockedConnect$0(ReconnectPromise.java:114) ~[bundleFile:?] at org.opendaylight.netconf.nettyutil.AbstractNetconfDispatcher$3.initChannel(AbstractNetconfDispatcher.java:202) ~[bundleFile:?] at org.opendaylight.netconf.nettyutil.AbstractNetconfDispatcher$3.initChannel(AbstractNetconfDispatcher.java:199) ~[bundleFile:?] at io.netty.channel.ChannelInitializer.initChannel(ChannelInitializer.java:129) [bundleFile:4.1.69.Final] at io.netty.channel.ChannelInitializer.handlerAdded(ChannelInitializer.java:112) [bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannelHandlerContext.callHandlerAdded(AbstractChannelHandlerContext.java:938) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:609) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.access$100(DefaultChannelPipeline.java:46) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline$PendingHandlerAddedTask.execute(DefaultChannelPipeline.java:1463) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.callHandlerAddedForAllHandlers(DefaultChannelPipeline.java:1115) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.invokeHandlerAddedIfNeeded(DefaultChannelPipeline.java:650) [bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannel$AbstractUnsafe.register0(AbstractChannel.java:514) [bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannel$AbstractUnsafe.access$200(AbstractChannel.java:429) [bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannel$AbstractUnsafe$1.run(AbstractChannel.java:486) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) [bundleFile:4.1.69.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) [bundleFile:4.1.69.Final] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [bundleFile:4.1.69.Final] at java.lang.Thread.run(Unknown Source) [?:?]2022-01-26T08:21:56,836 | WARN  | globalWorkerGroup-3-7 | ChannelInitializer               | 66 - io.netty.common - 4.1.69.Final | Failed to initialize a channel. Closing: [id: 0x9516aa69]io.netty.channel.ChannelPipelineException: org.opendaylight.netconf.nettyutil.ReconnectPromise$1 is not a @Sharable handler, so can't be added or removed multiple times. at io.netty.channel.DefaultChannelPipeline.checkMultiplicity(DefaultChannelPipeline.java:600) ~[bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:202) ~[bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:381) ~[bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:370) ~[bundleFile:4.1.69.Final] at org.opendaylight.netconf.nettyutil.ReconnectPromise.lambda$lockedConnect$0(ReconnectPromise.java:114) ~[?:?] at org.opendaylight.netconf.nettyutil.AbstractNetconfDispatcher$3.initChannel(AbstractNetconfDispatcher.java:202) ~[?:?] at org.opendaylight.netconf.nettyutil.AbstractNetconfDispatcher$3.initChannel(AbstractNetconfDispatcher.java:199) ~[?:?] at io.netty.channel.ChannelInitializer.initChannel(ChannelInitializer.java:129) [bundleFile:4.1.69.Final] at io.netty.channel.ChannelInitializer.handlerAdded(ChannelInitializer.java:112) [bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannelHandlerContext.callHandlerAdded(AbstractChannelHandlerContext.java:938) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:609) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.access$100(DefaultChannelPipeline.java:46) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline$PendingHandlerAddedTask.execute(DefaultChannelPipeline.java:1463) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.callHandlerAddedForAllHandlers(DefaultChannelPipeline.java:1115) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.invokeHandlerAddedIfNeeded(DefaultChannelPipeline.java:650) [bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannel$AbstractUnsafe.register0(AbstractChannel.java:514) [bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannel$AbstractUnsafe.access$200(AbstractChannel.java:429) [bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannel$AbstractUnsafe$1.run(AbstractChannel.java:486) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) [bundleFile:4.1.69.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) [bundleFile:4.1.69.Final] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [bundleFile:4.1.69.Final] at java.lang.Thread.run(Unknown Source) [?:?]2022-01-26T08:21:59,843 | WARN  | globalWorkerGroup-3-8 | ChannelInitializer               | 66 - io.netty.common - 4.1.69.Final | Failed to initialize a channel. Closing: [id: 0xa25801f3]io.netty.channel.ChannelPipelineException: org.opendaylight.netconf.nettyutil.ReconnectPromise$1 is not a @Sharable handler, so can't be added or removed multiple times. at io.netty.channel.DefaultChannelPipeline.checkMultiplicity(DefaultChannelPipeline.java:600) ~[bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:202) ~[bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:381) ~[bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.addLast(DefaultChannelPipeline.java:370) ~[bundleFile:4.1.69.Final] at org.opendaylight.netconf.nettyutil.ReconnectPromise.lambda$lockedConnect$0(ReconnectPromise.java:114) ~[?:?] at org.opendaylight.netconf.nettyutil.AbstractNetconfDispatcher$3.initChannel(AbstractNetconfDispatcher.java:202) ~[?:?] at org.opendaylight.netconf.nettyutil.AbstractNetconfDispatcher$3.initChannel(AbstractNetconfDispatcher.java:199) ~[?:?] at io.netty.channel.ChannelInitializer.initChannel(ChannelInitializer.java:129) [bundleFile:4.1.69.Final] at io.netty.channel.ChannelInitializer.handlerAdded(ChannelInitializer.java:112) [bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannelHandlerContext.callHandlerAdded(AbstractChannelHandlerContext.java:938) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:609) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.access$100(DefaultChannelPipeline.java:46) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline$PendingHandlerAddedTask.execute(DefaultChannelPipeline.java:1463) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.callHandlerAddedForAllHandlers(DefaultChannelPipeline.java:1115) [bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.invokeHandlerAddedIfNeeded(DefaultChannelPipeline.java:650) [bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannel$AbstractUnsafe.register0(AbstractChannel.java:514) [bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannel$AbstractUnsafe.access$200(AbstractChannel.java:429) [bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannel$AbstractUnsafe$1.run(AbstractChannel.java:486) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) [bundleFile:4.1.69.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) [bundleFile:4.1.69.Final] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [bundleFile:4.1.69.Final] at java.lang.Thread.run(Unknown Source) [?:?]2022-01-26T08:21:59,852 | ERROR | globalEventExecutor-1-4 | AbstractNetconfTopology          | 362 - org.opendaylight.netconf.topology - 2.0.11 | Connector for tlstest failedjava.lang.Throwable: Maximum reconnection attempts reached at org.opendaylight.netconf.nettyutil.TimedReconnectStrategy.scheduleReconnect(TimedReconnectStrategy.java:94) ~[bundleFile:?] at org.opendaylight.netconf.nettyutil.NetconfSessionPromise$BootstrapConnectListener.operationComplete(NetconfSessionPromise.java:116) ~[bundleFile:?] at org.opendaylight.netconf.nettyutil.NetconfSessionPromise$BootstrapConnectListener.operationComplete(NetconfSessionPromise.java:82) ~[bundleFile:?] at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:578) ~[bundleFile:4.1.69.Final] at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:552) ~[bundleFile:4.1.69.Final] at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:491) ~[bundleFile:4.1.69.Final] at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:616) ~[bundleFile:4.1.69.Final] at io.netty.util.concurrent.DefaultPromise.setFailure0(DefaultPromise.java:609) ~[bundleFile:4.1.69.Final] at io.netty.util.concurrent.DefaultPromise.tryFailure(DefaultPromise.java:117) ~[bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannel$AbstractUnsafe.safeSetFailure(AbstractChannel.java:1017) ~[bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannel$AbstractUnsafe.ensureOpen(AbstractChannel.java:1000) ~[bundleFile:4.1.69.Final] at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.connect(AbstractNioChannel.java:237) ~[bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline$HeadContext.connect(DefaultChannelPipeline.java:1342) ~[bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:548) ~[bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:533) ~[bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannelHandlerContext.connect(AbstractChannelHandlerContext.java:517) ~[bundleFile:4.1.69.Final] at io.netty.channel.DefaultChannelPipeline.connect(DefaultChannelPipeline.java:978) ~[bundleFile:4.1.69.Final] at io.netty.channel.AbstractChannel.connect(AbstractChannel.java:265) ~[bundleFile:4.1.69.Final] at io.netty.bootstrap.Bootstrap$3.run(Bootstrap.java:250) ~[bundleFile:4.1.69.Final] at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) ~[bundleFile:4.1.69.Final] at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) ~[bundleFile:4.1.69.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) ~[bundleFile:4.1.69.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) ~[bundleFile:4.1.69.Final] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [bundleFile:4.1.69.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [bundleFile:4.1.69.Final] at java.lang.Thread.run(Unknown Source) [?:?]
      

            rovarga Robert Varga
            metaljackL Michael Dürre
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: