[NETCONF-852] NETCONF mount fails during reconnect Created: 26/Jan/22 Updated: 11/Feb/22 Resolved: 27/Jan/22 |
|
| Status: | Resolved |
| Project: | netconf |
| Component/s: | netconf |
| Affects Version/s: | 2.0.4, 2.0.11 |
| Fix Version/s: | 2.0.13, 1.13.8 |
| Type: | Bug | Priority: | Medium |
| Reporter: | Michael Dürre | Assignee: | Robert Varga |
| Resolution: | Done | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Issue Links: |
|
||||||||
| Description |
|
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) [?:?] |
| Comments |
| Comment by Michael Dürre [ 27/Jan/22 ] |
|
Hi rovarga I am sorry, but the error message was caused by an internal problem on my dev VM. But there is a problem with the TLS mount from multiple persons in our company confirmed. "netconf-node-topology:connected-message": "javax.net.ssl.SSLHandshakeException: Received fatal alert: decrypt_error" So my question is: [1] should I create a new ticket for this? |
| Comment by Robert Varga [ 27/Jan/22 ] |
|
Since that is a different thing, please file a separate issues with the corresponding longs. |
| Comment by Michael Dürre [ 28/Jan/22 ] |
|
good point. |