can not clone by ssh 29418 -- SshChannelNotFoundException: Received SSH_MSG_CHANNEL_WINDOW_ADJUST on unknown channel 0

[Brent Huang]

my version is 3.0.1, on LinuxMint. my error is:

hgc@hgc-virtual-machine:~/Desktop$ git clone "ssh://huanggu...@118.31.111.174:29418/rd_doc" -v --progress

Cloning into 'rd_doc'...

remote: Counting objects: 1270, done

remote: Finding sources: 100% (1270/1270)

Connection to 118.31.111.174 closed by remote host..00 KiB/s    

fatal: The remote end hung up unexpectedly

fatal: early EOF

fatal: index-pack failed

hgc@hgc-virtual-machine:~/Desktop$ 

gerrit error_log is:

[2019-07-26 15:05:31,044] [sshd-SshServer[7f792530]-nio2-thread-2] WARN  org.apache.sshd.server.session.ServerSessionImpl : exceptionCaught(ServerSessionImpl[huangguangcheng@/222.42.76.8:63058])[state=Opened] SshChannelNotFoundException: Received SSH_MSG_CHANNEL_WINDOW_ADJUST on unknown channel 0

on windows10, when using git bash to clone, It failed too as above.

but when I use TortoiseGit GUI clone on windows10, it's ok. where is no problem.

I found the ssh client is: C:\Program Files\TortoiseGit\bin\TortoiseGitPlink.exe for TortoiseGit.  

maybe there are some difference between git.exe and TortoiseGitPlink.exe.

[Matthias Sohn]

On Fri, Jul 26, 2019 at 1:46 PM Brent Huang <guang2...@gmail.com> wrote:

my version is 3.0.1, on LinuxMint. my error is:

hgc@hgc-virtual-machine:~/Desktop$ git clone "ssh://huanggu...@118.31.111.174:29418/rd_doc" -v --progress

Cloning into 'rd_doc'...

remote: Counting objects: 1270, done

remote: Finding sources: 100% (1270/1270)

Connection to 118.31.111.174 closed by remote host..00 KiB/s    

fatal: The remote end hung up unexpectedly

fatal: early EOF

fatal: index-pack failed

hgc@hgc-virtual-machine:~/Desktop$ 

gerrit error_log is:

[2019-07-26 15:05:31,044] [sshd-SshServer[7f792530]-nio2-thread-2] WARN  org.apache.sshd.server.session.ServerSessionImpl : exceptionCaught(ServerSessionImpl[huangguangcheng@/222.42.76.8:63058])[state=Opened] SshChannelNotFoundException: Received SSH_MSG_CHANNEL_WINDOW_ADJUST on unknown channel 0

is there a stacktrace for this log entry ?

 

on windows10, when using git bash to clone, It failed too as above.

but when I use TortoiseGit GUI clone on windows10, it's ok. where is no problem.

I found the ssh client is: C:\Program Files\TortoiseGit\bin\TortoiseGitPlink.exe for TortoiseGit.  

maybe there are some difference between git.exe and TortoiseGitPlink.exe.

you can try to configure ssh to create verbose output to get more details:

$ GIT_SSH_COMMAND="ssh -vvv" git clone "ssh://huanggu...@118.31.111.174:29418/rd_doc" -v --progress

or put this in your ~/.ssh/config file:

Host <git-server-FQDN> LogLevel (QUIET|FATAL|ERROR|INFO|VERBOSE|DEBUG|DEBUG1|DEBUG2|DEBUG3)

when you try to clone again over ssh you should get ssh verbose output

-Matthias

[Åsmund Østvold]

Was there a solution to this issue?

We have the same issue and are happy to contribute out test findings. 

Thans,

Åsmund

 

-Matthias

--
--
To unsubscribe, email repo-discuss...@googlegroups.com
More info at http://groups.google.com/group/repo-discuss?hl=en

---
You received this message because you are subscribed to the Google Groups "Repo and Gerrit Discussion" group.
To unsubscribe from this group and stop receiving emails from it, send an email to repo-discuss...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/repo-discuss/CAKSZd3QqKiK6XQXfrqV_PDyqUPG7%3Dkr6%2BxKgM2mMshzmrOvC7A%40mail.gmail.com.

[Ovidiu Stanila]

Facing same kind of issue with a CentOS 6 client which can't clone one of our repositories:

# cat /root/.ssh/config
Host X.X.X.X
LogLevel DEBUG3

# git clone ssh://ovidiu....@X.X.X.X:29418/testing.git

Initialized empty Git repository in /tmp/testing/.git/
debug2: ssh_connect: needpriv 0
debug1: Connecting to X.X.X.X [X.X.X.X] port 29418.
debug1: Connection established.
debug1: permanently_set_uid: 0/0
debug1: identity file /root/.ssh/identity type -1
debug1: identity file /root/.ssh/identity-cert type -1
debug1: identity file /root/.ssh/id_rsa type -1
debug1: identity file /root/.ssh/id_rsa-cert type -1
debug3: Not a RSA1 key file /root/.ssh/id_dsa.
debug2: key_type_from_name: unknown key type '-----BEGIN'
debug3: key_read: missing keytype
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug2: key_type_from_name: unknown key type '-----END'
debug3: key_read: missing keytype
debug1: identity file /root/.ssh/id_dsa type 2
debug1: identity file /root/.ssh/id_dsa-cert type -1
debug1: identity file /root/.ssh/id_ecdsa type -1
debug1: identity file /root/.ssh/id_ecdsa-cert type -1
debug1: Remote protocol version 2.0, remote software version GerritCodeReview_3.0.1 (SSHD-CORE-2.0.0)
debug1: no match: GerritCodeReview_3.0.1 (SSHD-CORE-2.0.0)
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.3
debug2: fd 3 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug3: Wrote 864 bytes for a total of 885
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa-...@openssh.com,ssh-dss-...@openssh.com,ssh-rsa-...@openssh.com,ssh-dss-...@openssh.com,ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,rijnda...@lysator.liu.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,rijnda...@lysator.liu.se
debug2: kex_parse_kexinit: hmac-sha1,uma...@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ri...@openssh.com,hmac-sha1-96
debug2: kex_parse_kexinit: hmac-sha1,uma...@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ri...@openssh.com,hmac-sha1-96
debug2: kex_parse_kexinit: none,zl...@openssh.com,zlib
debug2: kex_parse_kexinit: none,zl...@openssh.com,zlib
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: kex_parse_kexinit: ecdh-sha2-nistp521,ecdh-sha2-nistp384,ecdh-sha2-nistp256,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group18-sha512,diffie-hellman-group17-sha512,diffie-hellman-group16-sha512,diffie-hellman-group15-sha512,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519,ecdsa-sha2-nistp521,ecdsa-sha2-nistp384
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,aes192-cbc,aes256-cbc
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,aes192-cbc,aes256-cbc
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha2-512,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha2-512,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none
debug2: kex_parse_kexinit: none
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: mac_setup: found hmac-sha1
debug1: kex: server->client aes128-ctr hmac-sha1 none
debug2: mac_setup: found hmac-sha1
debug1: kex: client->server aes128-ctr hmac-sha1 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<2048<8192) sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug3: Wrote 24 bytes for a total of 909
debug2: dh_gen_key: priv key bits set: 163/320
debug2: bits set: 1023/2048
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: Wrote 272 bytes for a total of 1181
debug3: put_host_port: [X.X.X.X]:29418
debug3: put_host_port: [X.X.X.X]:29418
debug3: check_host_in_hostfile: host [X.X.X.X]:29418 filename /root/.ssh/known_hosts
debug3: check_host_in_hostfile: host [X.X.X.X]:29418 filename /root/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 26
debug3: check_host_in_hostfile: host [X.X.X.X]:29418 filename /root/.ssh/known_hosts
debug3: check_host_in_hostfile: host [X.X.X.X]:29418 filename /root/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 26
debug1: Host '[X.X.X.X]:29418' is known and matches the RSA host key.
debug1: Found key in /root/.ssh/known_hosts:26
debug2: bits set: 1039/2048
debug1: ssh_rsa_verify: signature correct
debug2: kex_derive_keys
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: Wrote 16 bytes for a total of 1197
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug3: Wrote 52 bytes for a total of 1249
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: /root/.ssh/identity ((nil))
debug2: key: /root/.ssh/id_rsa ((nil))
debug2: key: /root/.ssh/id_dsa (0x7f0e77b148c0)
debug2: key: /root/.ssh/id_ecdsa ((nil))
debug3: Wrote 84 bytes for a total of 1333
debug1: Authentications that can continue: publickey
debug3: start over, passed a different list publickey
debug3: preferred gssapi-keyex,gssapi-with-mic,publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Trying private key: /root/.ssh/identity
debug3: no such identity: /root/.ssh/identity
debug1: Trying private key: /root/.ssh/id_rsa
debug3: no such identity: /root/.ssh/id_rsa
debug1: Offering public key: /root/.ssh/id_dsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug3: Wrote 532 bytes for a total of 1865
debug1: Server accepts key: pkalg ssh-dss blen 433
debug2: input_userauth_pk_ok: SHA1 fp c0:d7:f9:cc:6b:2b:37:35:97:53:79:d6:a5:49:3e:2b:31:09:73:60
debug3: sign_and_send_pubkey: DSA c0:d7:f9:cc:6b:2b:37:35:97:53:79:d6:a5:49:3e:2b:31:09:73:60
debug1: read PEM private key done: type DSA
debug3: Wrote 596 bytes for a total of 2461
debug1: Authentication succeeded (publickey).
debug2: fd 4 setting O_NONBLOCK
debug2: fd 5 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug1: Entering interactive session.
debug3: Wrote 68 bytes for a total of 2529
debug2: callback start
debug2: client_session2_setup: id 0
debug1: Sending environment.
debug3: Ignored env HOSTNAME
debug3: Ignored env TERM
debug3: Ignored env SHELL
debug3: Ignored env HISTSIZE
debug3: Ignored env SSH_CLIENT
debug3: Ignored env SSH_TTY
debug3: Ignored env USER
debug3: Ignored env LS_COLORS
debug3: Ignored env MAIL
debug3: Ignored env PATH
debug3: Ignored env PWD
debug1: Sending env LANG = en_US.UTF-8
debug2: channel 0: request env confirm 0
debug3: Ignored env HISTCONTROL
debug3: Ignored env SHLVL
debug3: Ignored env HOME
debug3: Ignored env GIT_SSH_COMMAND
debug3: Ignored env LOGNAME
debug3: Ignored env CVS_RSH
debug3: Ignored env SSH_CONNECTION
debug3: Ignored env LESSOPEN
debug3: Ignored env G_BROKEN_FILENAMES
debug3: Ignored env _
debug3: Ignored env OLDPWD
debug3: Ignored env GIT_DIR
debug1: Sending command: git-upload-pack '/testing.git'
debug2: channel 0: request exec confirm 1
debug2: fd 3 setting TCP_NODELAY
debug2: callback done
debug2: channel 0: open confirm rwindow 2097152 rmax 32768
debug3: Wrote 152 bytes for a total of 2681
debug2: channel_input_status_confirm: type 99 id 0
debug2: exec request accepted on channel 0
debug3: Wrote 260 bytes for a total of 2941
debug2: channel 0: window 1997355 sent adjust 99797
debug3: Wrote 52 bytes for a total of 2993
debug2: channel 0: window 1966080 sent adjust 131072iB/s 
debug3: Wrote 52 bytes for a total of 3045
debug2: channel 0: window 1966080 sent adjust 131072iB/s 
debug3: Wrote 52 bytes for a total of 3097
debug2: channel 0: window 1966080 sent adjust 131072iB/s 
debug3: Wrote 52 bytes for a total of 3149
debug2: channel 0: window 1966080 sent adjust 131072iB/s 
debug3: Wrote 52 bytes for a total of 3201
debug3: Wrote -1 bytes for a total of 3201
Write failed: Broken pipe

fatal: The remote end hung up unexpectedly
fatal: early EOF

fatal: index-pack failed

Gerrit logs show only this error:

[2019-08-16 22:45:36,314] [sshd-SshServer[612290d]-nio2-thread-2] WARN  org.apache.sshd.server.session.ServerSessionImpl : exceptionCaught(ServerSessionImpl[ovidiu.stanila@/Y.Y.Y.Y:48436])[state=Opened] SshChannelNotFoundException: Received SSH_MSG_CHANNEL_WINDOW_ADJUST on unknown channel 0

From other locations the clone works fine, even from a similarly configured CentOS 6 system.

Main difference is that the problematic CentOS 6 system does the access from behind an OpenVPN tunnel, but didn't have issues until now.

Is there anything else we should check ?

Thank you,

Ovidiu

On Friday, July 26, 2019 at 4:04:55 PM UTC+3, Matthias Sohn wrote:

On Fri, Jul 26, 2019 at 1:46 PM Brent Huang <guang2...@gmail.com> wrote:

my version is 3.0.1, on LinuxMint. my error is:

hgc@hgc-virtual-machine:~/Desktop$ git clone "ssh://huanggu...@118.31.111.174:29418/rd_doc" -v --progress

Cloning into 'rd_doc'...

remote: Counting objects: 1270, done

remote: Finding sources: 100% (1270/1270)

Connection to 118.31.111.174 closed by remote host..00 KiB/s    

fatal: The remote end hung up unexpectedly

fatal: early EOF

fatal: index-pack failed

hgc@hgc-virtual-machine:~/Desktop$ 

gerrit error_log is:

[2019-07-26 15:05:31,044] [sshd-SshServer[7f792530]-nio2-thread-2] WARN  org.apache.sshd.server.session.ServerSessionImpl : exceptionCaught(ServerSessionImpl[huangguangcheng@/222.42.76.8:63058])[state=Opened] SshChannelNotFoundException: Received SSH_MSG_CHANNEL_WINDOW_ADJUST on unknown channel 0

is there a stacktrace for this log entry ?

 

on windows10, when using git bash to clone, It failed too as above.

but when I use TortoiseGit GUI clone on windows10, it's ok. where is no problem.

I found the ssh client is: C:\Program Files\TortoiseGit\bin\TortoiseGitPlink.exe for TortoiseGit.  

maybe there are some difference between git.exe and TortoiseGitPlink.exe.

you can try to configure ssh to create verbose output to get more details:

$ GIT_SSH_COMMAND="ssh -vvv" git clone "ssh://huangguangcheng@118.31.111.174:29418/rd_doc" -v --progress

or put this in your ~/.ssh/config file:

Host <git-server-FQDN> LogLevel (QUIET|FATAL|ERROR|INFO|VERBOSE|DEBUG|DEBUG1|DEBUG2|DEBUG3)

[Doug Robinson]

What we're not seeing is the time between the "debug2" and "debug3" output.  The VPN may have slowed things down to the point where the overall operation timed out.  Injecting timestamps into the output stream with the "git clone" is one way to see this.

Or just tweak the timeouts to be higher.

debug2: kex_parse_kexinit: ssh-rsa-...@openssh.com,ssh-dss-...@openssh.com,ssh-rsa-c...@openssh.com,ssh-dss-c...@openssh.com,ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,rijndael-c...@lysator.liu.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,rijndael-c...@lysator.liu.se

[Doug Robinson]

Ovidiu Stanila:

Please do not reply directly to me.  Please reply to the board so the community can see the discussion.

> Yes, that might be the cause. After multiple tries the clone worked eventually for that repository. Are there any timeout values or other settings we could set to avoid such issues when the connection is slower ?

Please look through the documentation: https://gerrit-documentation.storage.googleapis.com/Documentation/3.0.1/config-gerrit.html

Search for "timeout".

Cheers.

Doug

debug2: kex_parse_kexinit: ssh-rsa-...@openssh.com,ssh-dss-ce...@openssh.com,ssh-rsa-ce...@openssh.com,ssh-dss-ce...@openssh.com,ssh-rsa,ssh-dss

[Ovidiu Stanila]

Although we don't face that anymore, as the connection with that particular system was better lately, I've increased sshd.waitTimeout to 60s. We'll see how that behaves on worse days.

Thanks Doug.