Details
-
Bug
-
Status: Resolved
-
Medium
-
Resolution: Done
-
Magnesium SR1
-
None
-
None
Description
In specific circumstances, when device is disconnected, can happen, that the keepalive task remain scheduled. The current scheduled keepalive task is kept in attribute and the methods editing this attribute are not synchronized.
After removing the connection to specific device
23 Jun 2020 09:12:51,909 [opendaylight-cluster-data-notification-dispatcher-43] DEBUG org.opendaylight.netconf.topology.impl.NetconfTopologyImpl - Config for node Uri{_value=01nvwlxeqqzopn11msh7fu50gsh4} deleted 23 Jun 2020 09:12:51,909 [opendaylight-cluster-data-notification-dispatcher-43] DEBUG org.opendaylight.netconf.topology.AbstractNetconfTopology - Disconnecting RemoteDevice{01nvwlxeqqzopn11msh7fu50gsh4} 23 Jun 2020 09:12:51,909 [opendaylight-cluster-data-notification-dispatcher-43] WARN org.opendaylight.netconf.sal.connect.netconf.listener.NetconfDeviceCommunicator - RemoteDevice{01nvwlxeqqzopn11msh7fu50gsh4}: Session terminated Session closed 23 Jun 2020 09:12:51,909 [nioEventLoopGroup-3-3] TRACE org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler - Closing SSH session on channel: [id: 0x9c0eecb1] with connect promise in state: AbstractBootstrap$PendingRegistrationPromise@3b2cdc4c(success) 23 Jun 2020 09:12:51,910 [nioEventLoopGroup-3-3] DEBUG org.apache.sshd.common.util.closeable.AbstractCloseable - close(ClientSessionImpl[root@/127.0.0.1:17830]) Closing gracefully 23 Jun 2020 09:12:51,910 [nioEventLoopGroup-3-3] DEBUG org.apache.sshd.client.session.ClientSessionImpl - signalAuthFailure(ClientSessionImpl[root@/127.0.0.1:17830]) type=SshException, signalled=false: Session is being closed 23 Jun 2020 09:12:51,910 [nioEventLoopGroup-3-3] DEBUG org.apache.sshd.common.util.closeable.AbstractCloseable - close(ClientConnectionService[ClientSessionImpl[root@/127.0.0.1:17830]]) Closing gracefully 23 Jun 2020 09:12:51,911 [nioEventLoopGroup-3-3] DEBUG org.apache.sshd.common.session.helpers.AbstractConnectionService - stopHeartBeat(ClientSessionImpl[root@/127.0.0.1:17830]) no heartbeat to stop 23 Jun 2020 09:12:51,911 [nioEventLoopGroup-3-3] DEBUG org.apache.sshd.common.util.closeable.AbstractCloseable - close([ChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[root@/127.0.0.1:17830][netconf]] cmd=SSH_MSG_CHANNEL_DATA) Closing gracefully 23 Jun 2020 09:12:51,912 [nioEventLoopGroup-3-3] DEBUG org.apache.sshd.common.util.closeable.AbstractCloseable - close([ChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[root@/127.0.0.1:17830][netconf]] cmd=SSH_MSG_CHANNEL_DATA][Graceful] - operationComplete() closed 23 Jun 2020 09:12:51,913 [nioEventLoopGroup-3-3] DEBUG org.apache.sshd.common.channel.AbstractChannel$GracefulChannelCloseable - close(ChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[root@/127.0.0.1:17830][netconf])[immediately=false] processing 23 Jun 2020 09:12:51,913 [nioEventLoopGroup-3-3] DEBUG org.apache.sshd.common.channel.AbstractChannel$GracefulChannelCloseable - close(ChannelSubsystem[id=0, recipient=0]-ClientSessionImpl[root@/127.0.0.1:17830][netconf])[immediately=false] send SSH_MSG_CHANNEL_CLOSE 23 Jun 2020 09:12:51,913 [opendaylight-cluster-data-notification-dispatcher-43] DEBUG org.opendaylight.netconf.sal.connect.netconf.sal.NetconfDeviceSalProvider$MountInstance - RemoteDevice{01nvwlxeqqzopn11msh7fu50gsh4}: TOPOLOGY Mountpoint removed from MD-SAL {closed=true, instance=org.opendaylight.mdsal.dom.spi.SimpleDOMMountPoint@5e293a4c} 23 Jun 2020 09:12:51,913 [nioEventLoopGroup-3-3] DEBUG org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler - SSH session closed on channel: [id: 0x9c0eecb1]
Recurring keepalive failure is present
23 Jun 2020 09:16:33,912 [default-scheduled-pool-6-1] WARN org.opendaylight.netconf.sal.connect.netconf.sal.KeepaliveSalFacade$Keepalive - RemoteDevice{01nvwlxeqqzopn11msh7fu50gsh4}: Keepalive RPC failed. Reconnecting netconf session. java.lang.IllegalStateException: Previous keepalive timed out at org.opendaylight.netconf.sal.connect.netconf.sal.KeepaliveSalFacade$Keepalive.run(KeepaliveSalFacade.java:199) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305) at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) 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:834) 23 Jun 2020 09:16:33,912 [default-scheduled-pool-6-1] INFO org.opendaylight.netconf.sal.connect.netconf.sal.KeepaliveSalFacade - RemoteDevice{01nvwlxeqqzopn11msh7fu50gsh4}: Reconnecting inactive netconf session 23 Jun 2020 09:18:33,913 [default-scheduled-pool-6-1] WARN org.opendaylight.netconf.sal.connect.netconf.sal.KeepaliveSalFacade$Keepalive - RemoteDevice{01nvwlxeqqzopn11msh7fu50gsh4}: Keepalive RPC failed. Reconnecting netconf session. java.lang.IllegalStateException: Previous keepalive timed out at org.opendaylight.netconf.sal.connect.netconf.sal.KeepaliveSalFacade$Keepalive.run(KeepaliveSalFacade.java:199) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305) at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) 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:834) 23 Jun 2020 09:18:33,913 [default-scheduled-pool-6-1] INFO org.opendaylight.netconf.sal.connect.netconf.sal.KeepaliveSalFacade - RemoteDevice{01nvwlxeqqzopn11msh7fu50gsh4}: Reconnecting inactive netconf session 23 Jun 2020 09:20:33,920 [default-scheduled-pool-6-1] WARN org.opendaylight.netconf.sal.connect.netconf.sal.KeepaliveSalFacade$Keepalive - RemoteDevice{01nvwlxeqqzopn11msh7fu50gsh4}: Keepalive RPC failed. Reconnecting netconf session. java.lang.IllegalStateException: Previous keepalive timed out at org.opendaylight.netconf.sal.connect.netconf.sal.KeepaliveSalFacade$Keepalive.run(KeepaliveSalFacade.java:199) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:305) at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) 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:834) 23 Jun 2020 09:20:33,921 [default-scheduled-pool-6-1] INFO org.opendaylight.netconf.sal.connect.netconf.sal.KeepaliveSalFacade - RemoteDevice{01nvwlxeqqzopn11msh7fu50gsh4}: Reconnecting inactive netconf session
Attachments
Issue Links
- split to
-
NETCONF-717 Rework KeepaliveSalFacade time tracking
-
- Resolved
-
