[SSHD-28] Deadlock between execute thread and NioProcessor thread

• Type: Bug
• Status: Resolved
• Priority: Blocker
• Resolution: Fixed
• Fix Version/s: 0.2.0
• Assignee: Unassigned
• Reporter: Shawn Pearce
• Created: 12/Jun/09 17:41
• Updated: 27/Jul/09 14:02
• Resolved: 27/Jul/09 14:02

Description

We've identified a deadlock. Essentially our application creates a new Thread during Command.start(), and that new thread performs IO through the supplied input and output streams. The git-upload-pack thread is this new thread and the NioProcessor-5 is the elected processor thread.

From the trace below, it appears that the LoggingFilterOutputStream's close() is implicitly calling the ChannelOutputStream's flush(), which requires taking the lock, but the lock is already held by the command thread while it is waiting for space in the window, space which will never arrive since the channel is being closed.

I'm going to try to work out a patch for this... but I'd appreciate any insight you might have for it.

"Execute git-upload-pack" prio=10 tid=0x00007f6e4c465000 nid=0x12d2 in Object.wait() [0x00000000441c7000..0x00000000441c7da0]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at org.apache.sshd.common.channel.Window.waitAndConsume(Window.java:122)

• locked <0x00007f6e81e187d8> (a org.apache.sshd.common.channel.Window)
  at org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:89)
• locked <0x00007f6e81e18920> (a org.apache.sshd.common.channel.ChannelOutputStream)
  at org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:65)
• locked <0x00007f6e81e18920> (a org.apache.sshd.common.channel.ChannelOutputStream)
  at org.apache.sshd.common.util.LoggingFilterOutputStream.write(LoggingFilterOutputStream.java:55)
  at org.spearce.jgit.transport.PacketLineOut.writeChannelPacket(PacketLineOut.java:71)
  at org.spearce.jgit.transport.SideBandOutputStream.write(SideBandOutputStream.java:83)
  at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)

"NioProcessor-5" prio=10 tid=0x00000000403fa000 nid=0x3f3 waiting for monitor entry [0x00000000436bc000..0x00000000436bcd20]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:77)

• waiting to lock <0x00007f6e81e18920> (a org.apache.sshd.common.channel.ChannelOutputStream)
  at java.io.FilterOutputStream.flush(FilterOutputStream.java:123)
  at java.io.FilterOutputStream.close(FilterOutputStream.java:140)
  at org.apache.sshd.common.util.IoUtils.closeQuietly(IoUtils.java:35)
  at org.apache.sshd.server.channel.ChannelSession$1.operationComplete(ChannelSession.java:137)
  at org.apache.sshd.common.future.DefaultSshFuture.notifyListener(DefaultSshFuture.java:339)
  at org.apache.sshd.common.future.DefaultSshFuture.addListener(DefaultSshFuture.java:289)
  at org.apache.sshd.server.channel.ChannelSession.close(ChannelSession.java:131)
  at org.apache.sshd.common.session.AbstractSession.close(AbstractSession.java:282)
• locked <0x00007f6e682ddb70> (a java.lang.Object)
  at org.apache.sshd.server.session.ServerSession.close(ServerSession.java:87)
  at org.apache.sshd.common.AbstractSessionIoHandler.sessionClosed(AbstractSessionIoHandler.java:43)