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

Deadlock between AsyncSshHandler and AsyncSshHandlerReader

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: High High
    • Sodium
    • None
    • netconf
    • Ubuntu 16.04

      openjdk version "1.8.0_151"

       

      We met a deadlock recently  between AsyncSshHandler and AsyncSshHandlerReader:

      Deadlock happend as the following path:

                                                                                       ReadException happend

                                                                                         operationComplete

                                                                                             |

      Something failed happend -> close -> SH -> disconnect -> SHR -> close

                                                                |                              |

                                                                | <------------ invokeDisconnect

                               

      (SH stands for lock instance of AsyncSshHandler and SHR stands for lock instance of AsyncSshHandlerReader)

       

       

      Found one Java-level deadlock:
      =============================
      "sshd-SshClient[4b240240]-nio2-thread-6":
        waiting to lock monitor 0x00007f68c405bc48 (object 0x0000000096086638, a org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler),
        which is held by "nioEventLoopGroupCloseable-3-1"
      "nioEventLoopGroupCloseable-3-1":
        waiting to lock monitor 0x00007f68e9387308 (object 0x0000000096217a90, a org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandlerReader),
        which is held by "sshd-SshClient[4b240240]-nio2-thread-6"

      Java stack information for the threads listed above:
      ===================================================
      "sshd-SshClient[4b240240]-nio2-thread-6":
          at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler.disconnect(AsyncSshHandler.java:256)
          - waiting to lock <0x0000000096086638> (a org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler)
          at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler$5.close(AsyncSshHandler.java:197)
          at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandlerReader.invokeDisconnect(AsyncSshHandlerReader.java:82)
          at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandlerReader.operationComplete(AsyncSshHandlerReader.java:62)
          - locked <0x0000000096217a90> (a org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandlerReader)
          at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandlerReader.operationComplete(AsyncSshHandlerReader.java:24)
          at org.apache.sshd.common.future.DefaultSshFuture.notifyListener(DefaultSshFuture.java:269)
          at org.apache.sshd.common.future.DefaultSshFuture.notifyListeners(DefaultSshFuture.java:254)
          at org.apache.sshd.common.future.DefaultSshFuture.setValue(DefaultSshFuture.java:173)
          at org.apache.sshd.common.channel.ChannelAsyncInputStream.preClose(ChannelAsyncInputStream.java:73)
          - locked <0x0000000096217930> (a org.apache.sshd.common.util.Buffer)
          at org.apache.sshd.common.util.CloseableUtils$AbstractCloseable.close(CloseableUtils.java:284)
          at org.apache.sshd.common.util.CloseableUtils$ParallelCloseable.doClose(CloseableUtils.java:182)
          at org.apache.sshd.common.util.CloseableUtils$SimpleCloseable.close(CloseableUtils.java:151)
          at org.apache.sshd.common.util.CloseableUtils$SequentialCloseable$1.operationComplete(CloseableUtils.java:205)
          at org.apache.sshd.common.util.CloseableUtils$SequentialCloseable$1.operationComplete(CloseableUtils.java:200)
          at org.apache.sshd.common.future.DefaultSshFuture.notifyListener(DefaultSshFuture.java:269)
          at org.apache.sshd.common.future.DefaultSshFuture.addListener(DefaultSshFuture.java:214)
          at org.apache.sshd.common.util.CloseableUtils$SequentialCloseable$1.operationComplete(CloseableUtils.java:206)
          at org.apache.sshd.common.util.CloseableUtils$SequentialCloseable$1.operationComplete(CloseableUtils.java:200)
          at org.apache.sshd.common.future.DefaultSshFuture.notifyListener(DefaultSshFuture.java:269)
          at org.apache.sshd.common.future.DefaultSshFuture.addListener(DefaultSshFuture.java:214)
          at org.apache.sshd.common.util.CloseableUtils$SequentialCloseable$1.operationComplete(CloseableUtils.java:206)
          at org.apache.sshd.common.util.CloseableUtils$SequentialCloseable$1.operationComplete(CloseableUtils.java:200)
          at org.apache.sshd.common.util.CloseableUtils$SequentialCloseable.doClose(CloseableUtils.java:215)
          at org.apache.sshd.common.util.CloseableUtils$SimpleCloseable.close(CloseableUtils.java:151)
          at org.apache.sshd.common.util.CloseableUtils$AbstractInnerCloseable.doCloseGracefully(CloseableUtils.java:351)
          at org.apache.sshd.common.util.CloseableUtils$AbstractCloseable.close(CloseableUtils.java:285)
          at org.apache.sshd.common.channel.AbstractChannel.handleClose(AbstractChannel.java:148)
          at org.apache.sshd.common.session.AbstractConnectionService.channelClose(AbstractConnectionService.java:263)
          at org.apache.sshd.common.session.AbstractConnectionService.process(AbstractConnectionService.java:171)
          at org.apache.sshd.common.session.AbstractSession.doHandleMessage(AbstractSession.java:431)
          at org.apache.sshd.common.session.AbstractSession.handleMessage(AbstractSession.java:326)
          - locked <0x00000000960868b8> (a java.lang.Object)
          at org.apache.sshd.client.session.ClientSessionImpl.handleMessage(ClientSessionImpl.java:306)
          - locked <0x00000000960868b8> (a java.lang.Object)
          at org.apache.sshd.common.session.AbstractSession.decode(AbstractSession.java:780)
          at org.apache.sshd.common.session.AbstractSession.messageReceived(AbstractSession.java:308)
          - locked <0x000000009608a3b8> (a java.lang.Object)
          at org.apache.sshd.common.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:54)
          at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:184)
          at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:170)
          at org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:32)
          at java.security.AccessController.doPrivileged(Native Method)
          at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:30)
          at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
          at sun.nio.ch.Invoker$2.run(Invoker.java:218)
          at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
          at java.lang.Thread.run(Thread.java:745)
      "nioEventLoopGroupCloseable-3-1":
          at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandlerReader.close(AsyncSshHandlerReader.java:92)
          - waiting to lock <0x0000000096217a90> (a org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandlerReader)
          at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler.disconnect(AsyncSshHandler.java:268)
          - locked <0x0000000096086638> (a org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler)
          at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler.close(AsyncSshHandler.java:251)
          at io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:604)
          at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:588)
          at io.netty.channel.ChannelOutboundHandlerAdapter.close(ChannelOutboundHandlerAdapter.java:71)
          at io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:604)
          at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:588)
          at io.netty.channel.ChannelOutboundHandlerAdapter.close(ChannelOutboundHandlerAdapter.java:71)
          at io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:604)
          at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:588)
          at io.netty.channel.AbstractChannelHandlerContext.close(AbstractChannelHandlerContext.java:445)
          at io.netty.channel.DefaultChannelPipeline.close(DefaultChannelPipeline.java:928)
          at io.netty.channel.AbstractChannel.close(AbstractChannel.java:187)
          at org.opendaylight.protocol.framework.AbstractSessionNegotiator.negotiationFailed(AbstractSessionNegotiator.java:53)
          at org.opendaylight.protocol.framework.AbstractSessionNegotiator$1.operationComplete(AbstractSessionNegotiator.java:70)
          at org.opendaylight.protocol.framework.AbstractSessionNegotiator$1.operationComplete(AbstractSessionNegotiator.java:65)
          at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:518)
          at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:492)
          at io.netty.util.concurrent.DefaultPromise.notifyListenersWithStackOverFlowProtection(DefaultPromise.java:431)
          at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:420)
          at io.netty.util.concurrent.DefaultPromise.addListener(DefaultPromise.java:167)
          at io.netty.channel.DefaultChannelPromise.addListener(DefaultChannelPromise.java:93)
          at io.netty.channel.DefaultChannelPromise.addListener(DefaultChannelPromise.java:28)
          at org.opendaylight.protocol.framework.AbstractSessionNegotiator.sendMessage(AbstractSessionNegotiator.java:64)
          at org.opendaylight.netconf.nettyutil.AbstractNetconfSessionNegotiator.start(AbstractNetconfSessionNegotiator.java:112)
          at org.opendaylight.netconf.nettyutil.AbstractNetconfSessionNegotiator.startNegotiation(AbstractNetconfSessionNegotiator.java:93)
          at org.opendaylight.protocol.framework.AbstractSessionNegotiator.channelActive(AbstractSessionNegotiator.java:82)
          at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:201)
          at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:187)
          at io.netty.channel.AbstractChannelHandlerContext.fireChannelActive(AbstractChannelHandlerContext.java:180)
          at io.netty.channel.ChannelInboundHandlerAdapter.channelActive(ChannelInboundHandlerAdapter.java:64)
          at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:201)
          at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:187)
          at io.netty.channel.AbstractChannelHandlerContext.fireChannelActive(AbstractChannelHandlerContext.java:180)
          at io.netty.channel.ChannelInboundHandlerAdapter.channelActive(ChannelInboundHandlerAdapter.java:64)
          at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:201)
          at io.netty.channel.AbstractChannelHandlerContext.access$200(AbstractChannelHandlerContext.java:33)
          at io.netty.channel.AbstractChannelHandlerContext$3.run(AbstractChannelHandlerContext.java:192)
          at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358)
          at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:394)
          at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)
          at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145)
          at java.lang.Thread.run(Thread.java:745)

            oleksii.mozghovyi Oleksii Mozghovyi
            springasa fenggang xiao
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: