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

Keepalive task could remain scheduled when concurrent operations

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Medium Medium
    • Aluminium, Magnesium SR2
    • Magnesium SR1
    • None
    • None

      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
      

       

       

            apuchyova Anna Bencúrová
            apuchyova Anna Bencúrová
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated:
              Resolved: