[SSHD-942] SSH session crashes on high latency network

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Workaround
• Affects Version/s: 1.7.0, 2.0.0, 2.3.0
• Assignee: Lyor Goldstein
• Reporter: David Ostrovsky
• Created: 19/Sep/19 18:50
• Updated: 09/Apr/21 06:07
• Resolved: 22/Sep/19 16:24

Description

Gerrit users report problem: [1] with git clone/fetch/pull operations on high latency network, after upgrading Gerrit to 2.16.x from 2.15.x that effectively means upgrade of SSHD from 1.6.0 to 1.7.0 and to 2.0.0.

The error on SSHD 2.0.0 (Gerrit 2.16) is:

[2019-09-16 10:27:14,256] [sshd-SshServer[24facb47]-nio2-thread-8] WARN org.apache.sshd.server.session.ServerSessionImpl : exceptionCaught(ServerSessionImpl[usexxx@/172.x.x.1:63306])[state=Opened] SshChannelNotFoundException: Received SSH_MSG_CHANNEL_WINDOW_ADJUST on unknown channel 0

Note that the attempt to upgrade SSHD in Gerrit to 2.3.0 in this CL: [2], didn't fix the problem:

[2019-09-17 14:05:27,923] [sshd-SshDaemon[189c6683](port=22)-nio2-thread-4] WARN org.apache.sshd.server.session.ServerSessionImpl : exceptionCaught(ServerSessionImpl[<username>@/<ip>:55212])[state=Opened] SshChannelNotFoundException: Received SSH_MSG_CHANNEL_WINDOW_ADJUST on unknown channel 3
[2019-09-17 14:05:27,924] [SSH git-upload-pack <repo> (<username>)] ERROR com.google.gerrit.sshd.BaseCommand : Internal server error (user <username> account 1000190) during git-upload-pack '<repo path>'
org.apache.sshd.common.channel.WindowClosedException: Already closed: Window[server/remote](ChannelSession[id=2, recipient=6]-ServerSessionImpl[<username>@/<ip>:55212])
 at org.apache.sshd.common.channel.Window.waitForCondition(Window.java:302)
 at org.apache.sshd.common.channel.Window.waitForSpace(Window.java:252)

Also note, that downgrade to 1.7.0: [3] didn't fix the problem either. Only after downgrade to SSH 1.6.0: [4] the problem disappeared, and only warnings left in the log:

[2019-09-18 09:24:52,755] [NioProcessor-2] WARN org.apache.sshd.server.session.ServerConnectionService : Received SSH_MSG_CHANNEL_CLOSE on unknown channel 12
[2019-09-18 09:24:52,756] [NioProcessor-2] WARN org.apache.sshd.server.session.ServerConnectionService : Received SSH_MSG_CHANNEL_CLOSE on unknown channel 13
[2019-09-18 09:25:02,576] [NioProcessor-2] WARN org.apache.sshd.server.session.ServerConnectionService : Received SSH_MSG_CHANNEL_CLOSE on unknown channel 15
[2019-09-18 09:25:36,508] [NioProcessor-2] WARN org.apache.sshd.server.session.ServerConnectionService : Received SSH_MSG_CHANNEL_CLOSE on unknown channel 18
[2019-09-18 09:25:57,527] [NioProcessor-2] WARN org.apache.sshd.server.session.ServerConnectionService : Received SSH_MSG_CHANNEL_CLOSE on unknown channel 19
[2019-09-18 09:30:16,488] [NioProcessor-2] WARN org.apache.sshd.server.session.ServerConnectionService : Received SSH_MSG_CHANNEL_CLOSE on unknown channel 21

[1] https://bugs.chromium.org/p/gerrit/issues/detail?id=11491
[2] https://gerrit-review.googlesource.com/c/gerrit/+/207752
[3] https://gerrit-review.googlesource.com/c/gerrit/+/237730
[4] https://gerrit-review.googlesource.com/c/gerrit/+/237731