[SSHD-631] Deadlock on stream flush in command from callback thread

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Cannot Reproduce
• Assignee: Unassigned
• Reporter: Eugene Petrenko
• Created: 26/Jan/16 20:36
• Updated: 08/Jun/22 06:46
• Resolved: 08/Jun/22 06:46

Description

Command is running in the pooled thread and calls flush. Meanwhile, command staring code also calls flush (because of a bug from my side) to the same stream. Finally we have a deadlock if exception is thrown from channel

"sshd-nio2-14" Id=119 BLOCKED on org.apache.sshd.common.channel.ChannelOutputStream@26f0deaf owned by "ssh-commands-8" Id=175
  at org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:118)
  -  blocked on org.apache.sshd.common.channel.ChannelOutputStream@26f0deaf
  at jetbrains.vcs.server.settings.util.FileUtil.flushAndCatch(FileUtil.java:205)
  at jetbrains.ssh.server.command.BaseCommand.start(BaseCommand.java:51)
  at org.apache.sshd.server.channel.ChannelSession.handleExec(ChannelSession.java:495)
  at org.apache.sshd.server.channel.ChannelSession.handleRequest(ChannelSession.java:330)
  at org.apache.sshd.server.channel.ChannelSession$ChannelSessionRequestHandler.process(ChannelSession.java:680)
  at org.apache.sshd.server.channel.ChannelSession$ChannelSessionRequestHandler.process(ChannelSession.java:673)
  at org.apache.sshd.common.channel.AbstractChannel.handleRequest(AbstractChannel.java:153)
  at org.apache.sshd.common.session.AbstractConnectionService.channelRequest(AbstractConnectionService.java:321)
  at org.apache.sshd.common.session.AbstractConnectionService.process(AbstractConnectionService.java:194)
  at org.apache.sshd.common.session.AbstractSession.doHandleMessage(AbstractSession.java:401)
  at org.apache.sshd.common.session.AbstractSession.handleMessage(AbstractSession.java:349)
  -  locked java.lang.Object@521226a1
  at org.apache.sshd.common.session.AbstractSession.decode(AbstractSession.java:848)
  at org.apache.sshd.common.session.AbstractSession.messageReceived(AbstractSession.java:331)
  -  locked java.lang.Object@5df68b49
  at org.apache.sshd.common.session.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:57)
  at org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:220)
  at org.apache.sshd.common.io.nio2.Nio2Session$2.onCompleted(Nio2Session.java:212)
  at org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:34)
  at java.security.AccessController.doPrivileged(Native Method)
  at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:31)
  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 jetbrains.vcs.server.settings.util.DaemonThreadFactory$1.run(DaemonThreadFactory.java:32)
  at java.lang.Thread.run(Thread.java:745)

"sshd-nio2-38" Id=144 BLOCKED on java.lang.Object@521226a1 owned by "sshd-nio2-14" Id=119
  at org.apache.sshd.common.session.AbstractSession.exceptionCaught(AbstractSession.java:505)
  -  blocked on java.lang.Object@521226a1
  at org.apache.sshd.common.session.AbstractSessionIoHandler.exceptionCaught(AbstractSessionIoHandler.java:49)
  at org.apache.sshd.common.io.nio2.Nio2Session.exceptionCaught(Nio2Session.java:137)
  at org.apache.sshd.common.io.nio2.Nio2Session.access$500(Nio2Session.java:46)
  at org.apache.sshd.common.io.nio2.Nio2Session$3.onFailed(Nio2Session.java:278)
  at org.apache.sshd.common.io.nio2.Nio2CompletionHandler$2.run(Nio2CompletionHandler.java:45)
  at java.security.AccessController.doPrivileged(Native Method)
  at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.failed(Nio2CompletionHandler.java:42)
  at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:128)
  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 jetbrains.vcs.server.settings.util.DaemonThreadFactory$1.run(DaemonThreadFactory.java:32)
  at java.lang.Thread.run(Thread.java:745)

"ssh-commands-8" Id=175 WAITING on org.apache.sshd.common.channel.Window@32ef1edd
  at java.lang.Object.$$YJP$$wait(Native Method)
  -  waiting on org.apache.sshd.common.channel.Window@32ef1edd
  at java.lang.Object.wait(Object.java)
  at java.lang.Object.wait(Object.java:502)
  at org.apache.sshd.common.channel.Window.waitForSpace(Window.java:175)
  at org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:126)
  -  locked org.apache.sshd.common.channel.ChannelOutputStream@26f0deaf
  at org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:93)
  -  locked org.apache.sshd.common.channel.ChannelOutputStream@26f0deaf
  at java.io.OutputStream.write(OutputStream.java:75)
  <...>
  at jetbrains.ssh.server.command.CommandThreadPool$1.call(CommandThreadPool.java:58)
  at java.util.concurrent.FutureTask.run(FutureTask.java:266)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
  at jetbrains.vcs.server.settings.util.DaemonThreadFactory$1.run(DaemonThreadFactory.java:32)
  at java.lang.Thread.run(Thread.java:745)