Issue 3685: SSH connections not properly closed on connection reset
Status:  Accepted
Owner:
Project Member Reported by dougk....@gmail.com, Nov 19, 2015
Affected Version: 2.10.6, 2.11.5

What steps will reproduce the problem?
1. Start a clone of a large repository
2. Add a SSH rule to block the connection to Gerrit (or otherwise disrupt the network connection)
3. Wait for SSH connection to time out on both ends
4. Reconnect and run "gerrit show-connections"

What is the expected output? What do you see instead?
I expect the SSH connection to be closed, but instead, a session lingers around:

Session     Start     Idle   User            Remote Host
--------------------------------------------------------------
e804c5a7 12:46:20 00:00:46   <user>          ?

Eventually, this leads to all connections for a particular user being exhausted.

Please provide any additional information below.
Server logs show the following:
[2015-11-19 12:46:20,814 -0600] e804c5a7 <user> a/<ID> LOGIN FROM <IP>
[2015-11-19 12:47:35,852 -0600] e804c5a7 <user> a/<ID> git-upload-pack.<REPO> 0ms 75027ms killed

[2015-11-19 12:47:35,850] WARN  com.google.gerrit.sshd.GerritServerSession : Exception caught
java.io.IOException: Connection reset by peer
        at sun.nio.ch.FileDispatcherImpl.read0(Native Method)
        at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
        at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
        at sun.nio.ch.IOUtil.read(IOUtil.java:197)
        at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380)
        at org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:302)
        at org.apache.mina.transport.socket.nio.NioProcessor.read(NioProcessor.java:45)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:694)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:668)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:657)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:67)
        at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1121)
        at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
        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)
[2015-11-19 12:47:35,856] ERROR com.google.gerrit.sshd.BaseCommand : Internal server error (user <USER> account <ID>) during git-upload-pack '<REPO>'
org.apache.sshd.common.SshException
        at org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:140)
        at org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:84)
        at org.eclipse.jgit.util.io.TimeoutOutputStream.write(TimeoutOutputStream.java:113)
        at org.eclipse.jgit.transport.SideBandOutputStream.writeBuffer(SideBandOutputStream.java:171)
        at org.eclipse.jgit.transport.SideBandOutputStream.write(SideBandOutputStream.java:151)
        at org.eclipse.jgit.internal.storage.pack.PackOutputStream.write(PackOutputStream.java:126)
        at org.eclipse.jgit.internal.storage.file.ByteArrayWindow.write(ByteArrayWindow.java:89)
        at org.eclipse.jgit.internal.storage.file.WindowCursor.copyPackAsIs(WindowCursor.java:248)
        at org.eclipse.jgit.internal.storage.file.PackFile.copyPackAsIs(PackFile.java:355)
        at org.eclipse.jgit.internal.storage.file.LocalCachedPack.copyAsIs(LocalCachedPack.java:85)
        at org.eclipse.jgit.internal.storage.file.WindowCursor.copyPackAsIs(WindowCursor.java:236)
        at org.eclipse.jgit.internal.storage.pack.PackWriter.writePack(PackWriter.java:971)
        at org.eclipse.jgit.transport.UploadPack.sendPack(UploadPack.java:1451)
        at org.eclipse.jgit.transport.UploadPack.sendPack(UploadPack.java:1305)
        at org.eclipse.jgit.transport.UploadPack.service(UploadPack.java:719)
        at org.eclipse.jgit.transport.UploadPack.upload(UploadPack.java:630)
        at com.google.gerrit.sshd.commands.Upload.runImpl(Upload.java:80)
        at com.google.gerrit.sshd.AbstractGitCommand.service(AbstractGitCommand.java:101)
        at com.google.gerrit.sshd.AbstractGitCommand.access$000(AbstractGitCommand.java:32)
        at com.google.gerrit.sshd.AbstractGitCommand$1.run(AbstractGitCommand.java:70)
        at com.google.gerrit.sshd.BaseCommand$TaskThunk.run(BaseCommand.java:445)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at com.google.gerrit.server.git.WorkQueue$Task.run(WorkQueue.java:379)
        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)
Caused by: java.lang.InterruptedException
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:502)
        at org.apache.sshd.common.channel.Window.waitForSpace(Window.java:152)
        at org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:116)
        ... 28 more
Nov 20, 2015
Project Member #1 dougk....@gmail.com
Setting a breakpoint in AbstractSession.sessionClosed and AbstractSession.exceptionCaught (as well as CloseableUtils.close) seems to show that when an exception occurs as the session is closing, the resources are not properly released by the NioSocketAcceptor.  So, this seems like a bug in MINA, but haven't found exactly where yet. 
Nov 20, 2015
Project Member #2 dougk....@gmail.com
OK, this state seems to happen when an exception comes in as the session is closing: the NioSession's SelectionKey gets marked as invalid (I'm assuming because the underlying channel went away), which marks the SessionState as "CLOSING."  In AbstractPollingIoProcessor, the CLOSING state is simply skipped, and the session is never pruned from the list (removeNow is not called).  This issue seems to exist up through mina-core 2.0.9 which is used by sshd-1.0.0 (sshd-0.14.0 uses mina-core 2.0.8).

This has been reported upstream as https://issues.apache.org/jira/browse/SSHD-595
Nov 20, 2015
Project Member #3 dougk....@gmail.com
(No comment was entered for this change.)
Status: Accepted
Nov 20, 2015
Project Member #4 dougk....@gmail.com
(No comment was entered for this change.)
Owner: dougk....@gmail.com