PowerShell / Win32-OpenSSH

Win32 port of OpenSSH
7.33k stars 753 forks source link

Early EOF errors when running git fetch over ssh #1322

Closed congyiwu closed 3 years ago

congyiwu commented 5 years ago

If I configure the Git for Windows client to use the SSH version that ships with Windows, I occasionally see the following error during git fetch:

fatal: the remote end hung up unexpectedly
fatal: early EOF
fatal: index-pack failed

Here's a log that includes ssh -vvv output: fetch.log

And here's the test script that I used, which replays the same fetch 100 times in a row: fetchloop.sh.txt

I believe that this is a bug in the SSH client that ships with Windows, because:

The bug also seems data-shape dependent in that it reproduces more or less frequently depending on the exact state of the Git repos on the client and server. I have snapshots of the client and server Git repo state. I can't share it publicly, can can share it internally with Microsoft employees.

My client OS is Windows 10 1809 Build 17763.253 ((Get-Item (Get-Command sshd).Source).VersionInfo.FileVersion) says 7.7.2.2

The Git servers that I have tested against are:

From messing around with the Azure DevOps SSH code, I found the following:

So this looks like a race condition where channel data from the server is lost when the client receives SSH_MSG_CHANNEL_CLOSE.

BTW, I tried searching for related issues and found #752 and a few others, but they all seemed to be issues with running the Windows version of sshd on the server, as opposed to the client.

@dscho this should probably block https://github.com/git-for-windows/git/issues/1981

congyiwu commented 5 years ago

bump?

NoMoreFood commented 5 years ago

What is the latency between the client and server?

I'm willing to take a look at this, but I'd want some sort of repo snapshot (accessible to me) I know can reproduce the issue before diving into setting up a test.

petemounce commented 5 years ago

I think we're seeing this as well.

Windows 2016 Server, desktop edition. git for windows 2.21.0 via https://chocolatey.org/packages/git/2.21.0 openssh 7.9.0.0 via https://chocolatey.org/packages/openssh/7.9.0.1

ssh key is loaded into Windows ssh-agent service.

Verbose log output (using public repositories):

+ GIT_TRACE=1
+ GIT_TRACE_PACKET=1
+ GIT_TRACE_SETUP=1
+ GIT_CURL_VERBOSE=1
+ GIT_SSH_COMMAND='c:/Program\ Files/OpenSSH-Win64/ssh.exe -vvv'
+ git clone --verbose git@github.com:spatialos/gdk-for-unity-shared-ci.git /c/somewhere/2/gdk-for-unity-premerge/.shared-ci
13:39:23.682306 exec-cmd.c:236          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
13:39:23.683273 git.c:419               trace: built-in: git clone --verbose git@github.com:spatialos/gdk-for-unity-shared-ci.git C:/somewhere/2/gdk-for-unity-premerge/.shared-ci
13:39:23.696192 run-command.c:643       trace: run_command: unset GIT_DIR; 'c:/Program\ Files/OpenSSH-Win64/ssh.exe -vvv' git@github.com 'git-upload-pack '\''spatialos/gdk-for-unity-shared-ci.git'\'''
Cloning into 'C:/somewhere/2/gdk-for-unity-premerge/.shared-ci'...
bash.exe: warning: could not find /tmp, please create!
OpenSSH_for_Windows_7.9p1, LibreSSL 2.6.5
debug1: Reading configuration data C:\\Users\\someone-harmless/.ssh/config
debug1: C:\\Users\\someone-harmless/.ssh/config line 6: Applying options for *
debug1: C:\\Users\\someone-harmless/.ssh/config line 13: Applying options for github.com
debug3: Failed to open file:C:/ProgramData/ssh/ssh_config error:2
debug2: resolving "github.com" port 22
debug2: ssh_connect_direct
debug1: Connecting to github.com [140.82.118.3] port 22.
debug1: Connection established.
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_rsa error:2
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_rsa.pub error:2
debug1: identity file C:\\Users\\someone-harmless/.ssh/id_rsa type -1
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_rsa-cert error:2
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_rsa-cert.pub error:2
debug1: identity file C:\\Users\\someone-harmless/.ssh/id_rsa-cert type -1
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_dsa error:2
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_dsa.pub error:2
debug1: identity file C:\\Users\\someone-harmless/.ssh/id_dsa type -1
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_dsa-cert error:2
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_dsa-cert.pub error:2
debug1: identity file C:\\Users\\someone-harmless/.ssh/id_dsa-cert type -1
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_ecdsa error:2
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_ecdsa.pub error:2
debug1: identity file C:\\Users\\someone-harmless/.ssh/id_ecdsa type -1
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_ecdsa-cert error:2
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_ecdsa-cert.pub error:2
debug1: identity file C:\\Users\\someone-harmless/.ssh/id_ecdsa-cert type -1
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_ed25519 error:2
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_ed25519.pub error:2
debug1: identity file C:\\Users\\someone-harmless/.ssh/id_ed25519 type -1
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_ed25519-cert error:2
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_ed25519-cert.pub error:2
debug1: identity file C:\\Users\\someone-harmless/.ssh/id_ed25519-cert type -1
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_xmss error:2
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_xmss.pub error:2
debug1: identity file C:\\Users\\someone-harmless/.ssh/id_xmss type -1
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_xmss-cert error:2
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/id_xmss-cert.pub error:2
debug1: identity file C:\\Users\\someone-harmless/.ssh/id_xmss-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_for_Windows_7.9
debug1: Remote protocol version 2.0, remote software version babeld-d125c03e
debug1: no match: babeld-d125c03e
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to github.com:22 as 'git'
debug3: hostkeys_foreach: reading file "C:\\Users\\someone-harmless/.ssh/known_hosts"
debug3: record_hostkey: found key type RSA in file C:\\Users\\someone-harmless/.ssh/known_hosts:3
debug3: load_hostkeys: loaded 1 keys from github.com
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/known_hosts2 error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts2 error:2
debug3: order_hostkeyalgs: prefer hostkeyalgs: rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa
debug3: send packet: type 20
debug1: SSH2_MSG_KEXINIT sent
debug3: receive packet: type 20
debug1: SSH2_MSG_KEXINIT received
debug2: local client KEXINIT proposal
debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,ext-info-c
debug2: host key algorithms: rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ssh-ed25519-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519
debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none
debug2: compression stoc: none
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug2: peer server KEXINIT proposal
debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256
debug2: host key algorithms: ssh-dss,rsa-sha2-512,rsa-sha2-256,ssh-rsa
debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes256-gcm@openssh.com,aes128-gcm@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc
debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes256-gcm@openssh.com,aes128-gcm@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc
debug2: MACs ctos: hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: MACs stoc: hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none,zlib,zlib@openssh.com
debug2: compression stoc: none,zlib,zlib@openssh.com
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: rsa-sha2-512
debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none
debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none
debug3: send packet: type 30
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug3: receive packet: type 31
debug1: Server host key: ssh-rsa SHA256:nThbg6kXUpJWGl7E1IGOCspRomTxdCARLviKw6E5SY8
debug3: hostkeys_foreach: reading file "C:\\Users\\someone-harmless/.ssh/known_hosts"
debug3: record_hostkey: found key type RSA in file C:\\Users\\someone-harmless/.ssh/known_hosts:3
debug3: load_hostkeys: loaded 1 keys from github.com
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/known_hosts2 error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts2 error:2
debug3: hostkeys_foreach: reading file "C:\\Users\\someone-harmless/.ssh/known_hosts"
debug3: record_hostkey: found key type RSA in file C:\\Users\\someone-harmless/.ssh/known_hosts:5
debug3: load_hostkeys: loaded 1 keys from 140.82.118.3
debug3: Failed to open file:C:/Users/someone-harmless/.ssh/known_hosts2 error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts2 error:2
debug1: Host 'github.com' is known and matches the RSA host key.
debug1: Found key in C:\\Users\\someone-harmless/.ssh/known_hosts:3
Host key fingerprint is SHA256:nThbg6kXUpJWGl7E1IGOCspRomTxdCARLviKw6E5SY8
+---[RSA 2048]----+
| =+o...+=o..     |
|o++... *o .      |
|*.o.  *o.        |
|oo.  ..o.= .     |
|.+o. .. S =      |
|*=+ .  o = .     |
|OE .  . o        |
| o     .         |
|                 |
+----[SHA256]-----+
debug3: send packet: type 21
debug2: set_newkeys: mode 1
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: receive packet: type 21
debug1: SSH2_MSG_NEWKEYS received
debug2: set_newkeys: mode 0
debug1: rekey after 134217728 blocks
debug1: Will attempt key: c:/users/someone-harmless/nothing-to-see-here RSA SHA256:some-key-signature agent
debug1: Will attempt key: C:\\Users\\someone-harmless/.ssh/id_rsa
debug1: Will attempt key: C:\\Users\\someone-harmless/.ssh/id_dsa
debug1: Will attempt key: C:\\Users\\someone-harmless/.ssh/id_ecdsa
debug1: Will attempt key: C:\\Users\\someone-harmless/.ssh/id_ed25519
debug1: Will attempt key: C:\\Users\\someone-harmless/.ssh/id_xmss
debug2: pubkey_prepare: done
debug3: send packet: type 5
debug3: receive packet: type 7
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_input_ext_info: server-sig-algs=<ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-rsa,rsa-sha2-512,rsa-sha2-256,ssh-dss>
debug3: receive packet: type 6
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug3: send packet: type 50
debug3: receive packet: type 51
debug1: Authentications that can continue: publickey
debug3: start over, passed a different list publickey
debug3: preferred 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: Offering public key: c:/users/someone-harmless/nothing-to-see-here RSA SHA256:some-key-signature agent
debug3: send packet: type 50
debug2: we sent a publickey packet, wait for reply
debug3: receive packet: type 60
debug1: Server accepts key: c:/users/someone-harmless/nothing-to-see-here RSA SHA256:some-key-signature agent
debug3: sign_and_send_pubkey: RSA SHA256:some-key-signature
debug3: sign_and_send_pubkey: signing using rsa-sha2-512
debug3: send packet: type 50
debug3: receive packet: type 52
debug1: Authentication succeeded (publickey).
Authenticated to github.com ([140.82.118.3]:22).
debug2: fd 5 setting O_NONBLOCK
debug2: fd 6 setting O_NONBLOCK
debug2: fd 7 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug3: send packet: type 90
debug1: Entering interactive session.
debug1: pledge: network
debug3: receive packet: type 91
debug2: channel_input_open_confirmation: channel 0: callback start
debug2: fd 3 setting TCP_NODELAY
debug2: client_session2_setup: id 0
debug1: Sending command: git-upload-pack 'spatialos/gdk-for-unity-shared-ci.git'
debug2: channel 0: request exec confirm 1
debug3: send packet: type 98
debug2: channel_input_open_confirmation: channel 0: callback done
debug2: channel 0: open confirm rwindow 32000 rmax 35000
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: exec request accepted on channel 0
13:39:24.767552 pkt-line.c:80           packet:        clone< 8f6b03dbc78f507f6753663bc7480d1ee2c2f2b1 HEAD\0multi_ack thin-pack side-band side-band-64k ofs-delta shallow deepen-since deepen-not deepen-relative no-progress include-tag multi_ack_detailed symref=HEAD:refs/heads/master agent=git/github-g14823918a5db
13:39:24.767552 pkt-line.c:80           packet:        clone< 4ff2cf8863123af0a933c8d46f1028dd1cded4c7 refs/heads/feature/add-test-runner
13:39:24.768613 pkt-line.c:80           packet:        clone< 59dbfe262747d735e206fdbb32e963f6adeeab4b refs/heads/feature/api-docs-generator
13:39:24.768613 pkt-line.c:80           packet:        clone< abf7edaa258bd6e24a3f46178f0c1841e49fd1c3 refs/heads/feature/buildkite_premerge
13:39:24.768613 pkt-line.c:80           packet:        clone< 9753b61daac9ab12e2048d799d6985d4e7ddb3ec refs/heads/feature/ci-pipefail-fix
13:39:24.768613 pkt-line.c:80           packet:        clone< 995cc8471eb4f13779a25c51f8402840a55ebb06 refs/heads/feature/release-tool
13:39:24.768613 pkt-line.c:80           packet:        clone< 8f6b03dbc78f507f6753663bc7480d1ee2c2f2b1 refs/heads/master
13:39:24.768613 pkt-line.c:80           packet:        clone< e915467132935c74cc68be9e42f4165d4efb7e10 refs/pull/1/head
13:39:24.768613 pkt-line.c:80           packet:        clone< d6e6eff1a7356835a759c51176cf5a128f7bf47f refs/pull/10/head
13:39:24.768613 pkt-line.c:80           packet:        clone< be5ab167ac8e0930cb37ad5f4895d52b35b8d425 refs/pull/11/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 59dbfe262747d735e206fdbb32e963f6adeeab4b refs/pull/12/head
13:39:24.768613 pkt-line.c:80           packet:        clone< e099c93243af35974200acc44f387fdfde556cec refs/pull/13/head
13:39:24.768613 pkt-line.c:80           packet:        clone< be5ab167ac8e0930cb37ad5f4895d52b35b8d425 refs/pull/14/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 4a7ced7335017e8b8563790a3a350500ade199bf refs/pull/15/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 08d1e889439670b5fed0464d1182d9331d519166 refs/pull/16/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 0a6feaef63c327130d919157f9b35392b1e5f79f refs/pull/17/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 989ea6b4e240502f8de055431b56c234d77cbe0b refs/pull/18/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 060747b0a81506d0f8f9b98a5156633b5dfe7caa refs/pull/19/head
13:39:24.768613 pkt-line.c:80           packet:        clone< a9885703dea124e67e85a53e6e28cdea9f7c62fb refs/pull/2/head
13:39:24.768613 pkt-line.c:80           packet:        clone< f4b7b16934cd544468afcc4b2397fb54de6b1493 refs/pull/20/head
13:39:24.768613 pkt-line.c:80           packet:        clone< ecac4ae9159feaf301d038cbd642a0c66e06eb13 refs/pull/21/head
13:39:24.768613 pkt-line.c:80           packet:        clone< abf7edaa258bd6e24a3f46178f0c1841e49fd1c3 refs/pull/22/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 107a7183bf750b44e52c8117639491dcb1c93c97 refs/pull/23/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 995cc8471eb4f13779a25c51f8402840a55ebb06 refs/pull/24/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 8a58a3d12d7d99291767aad5d0f1ccc5d49b1e01 refs/pull/25/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 05295c4d819273d55ec684bfa17f603693cd3154 refs/pull/26/head
13:39:24.768613 pkt-line.c:80           packet:        clone< aaf3e032761242010345680ac247f6b191211d13 refs/pull/27/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 45e1c0579a64316bcef4d0bf1fabf3e02311305f refs/pull/28/head
13:39:24.768613 pkt-line.c:80           packet:        clone< fea48547a6393c3968b58b0de4bbf3e73fb5d579 refs/pull/29/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 47f1279126a218aea387a63b442d54bdd2d76f5d refs/pull/3/head
13:39:24.768613 pkt-line.c:80           packet:        clone< c16dbba21065767ad729bf5e40585d9352549558 refs/pull/30/head
13:39:24.768613 pkt-line.c:80           packet:        clone< d39c743b78209750580be152e15f1b724649a261 refs/pull/31/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 09a1c68285ca57a94d0cf6771123cb0d6212b772 refs/pull/4/head
13:39:24.768613 pkt-line.c:80           packet:        clone< bd276089863db4ec6a8ec06dcdec74f9c129f419 refs/pull/5/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 3640f47a1a4b41747b49b34ad22ced2371b31824 refs/pull/6/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 4ff2cf8863123af0a933c8d46f1028dd1cded4c7 refs/pull/7/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 54367fb969625c43a214c574c4e023a7d4704dbd refs/pull/8/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 49e01a15aee1392a66831915c3aefd8d56593fe9 refs/pull/9/head
13:39:24.768613 pkt-line.c:80           packet:        clone< 0000
13:39:24.771174 pkt-line.c:80           packet:        clone> want 8f6b03dbc78f507f6753663bc7480d1ee2c2f2b1 multi_ack_detailed side-band-64k thin-pack no-progress ofs-delta deepen-since deepen-not agent=git/2.21.0.windows.1
13:39:24.771174 pkt-line.c:80           packet:        clone> want 4ff2cf8863123af0a933c8d46f1028dd1cded4c7
13:39:24.771174 pkt-line.c:80           packet:        clone> want 59dbfe262747d735e206fdbb32e963f6adeeab4b
13:39:24.771174 pkt-line.c:80           packet:        clone> want abf7edaa258bd6e24a3f46178f0c1841e49fd1c3
13:39:24.771174 pkt-line.c:80           packet:        clone> want 9753b61daac9ab12e2048d799d6985d4e7ddb3ec
13:39:24.771174 pkt-line.c:80           packet:        clone> want 995cc8471eb4f13779a25c51f8402840a55ebb06
13:39:24.771174 pkt-line.c:80           packet:        clone> want 8f6b03dbc78f507f6753663bc7480d1ee2c2f2b1
13:39:24.771174 pkt-line.c:80           packet:        clone> 0000
13:39:24.771174 pkt-line.c:80           packet:        clone> done
debug2: channel 0: rcvd adjust 1248470
13:39:24.906427 pkt-line.c:80           packet:        clone< NAK
13:39:24.920583 run-command.c:643       trace: run_command: git index-pack --stdin --fix-thin '--keep=fetch-pack 14780 on some-uninteresting-hostname' --check-self-contained-and-connected
13:39:24.927445 pkt-line.c:80           packet:     sideband< PACK ...
13:39:24.930373 exec-cmd.c:236          trace: resolved executable dir: C:/Program Files/Git/mingw64/libexec/git-core
13:39:24.932299 trace.c:377             setup: git_dir: C:/somewhere/2/gdk-for-unity-premerge/.shared-ci/.git
13:39:24.932299 trace.c:378             setup: git_common_dir: C:/somewhere/2/gdk-for-unity-premerge/.shared-ci/.git
13:39:24.932299 trace.c:379             setup: worktree: C:/somewhere/2/gdk-for-unity-premerge
13:39:24.932299 trace.c:380             setup: cwd: C:/somewhere/2/gdk-for-unity-premerge
13:39:24.932299 trace.c:381             setup: prefix: (null)
13:39:24.932299 git.c:419               trace: built-in: git index-pack --stdin --fix-thin '--keep=fetch-pack 14780 on some-uninteresting-hostname' --check-self-contained-and-connected
debug2: channel 0: window 1971561 sent adjust 125591
debug2: channel 0: window 1966082 sent adjust 131070
debug2: channel 0: window 1966082 sent adjust 65535
debug2: channel 0: window 1966082 sent adjust 131070
debug2: channel 0: window 1966082 sent adjust 65535
debug2: channel 0: window 1966082 sent adjust 65535
debug2: channel 0: window 1802254 sent adjust 102400
debug2: channel 0: window 1904654 sent adjust 102400
debug2: channel 0: window 1974277 sent adjust 122875
debug2: channel 0: window 1966082 sent adjust 131070
debug2: channel 0: window 1966082 sent adjust 32758
debug2: channel 0: window 1998840 sent adjust 98312
debug2: channel 0: window 1553527 sent adjust 102400
debug2: channel 0: window 1584080 sent adjust 102400
debug2: channel 0: window 1686480 sent adjust 102400
debug2: channel 0: window 1788880 sent adjust 102400
debug2: channel 0: window 1891280 sent adjust 102400
debug2: channel 0: window 1993680 sent adjust 102400
debug2: channel 0: window 1988551 sent adjust 75808
debug2: channel 0: window 1908651 sent adjust 102400
debug2: channel 0: window 1978274 sent adjust 86101
debug2: channel 0: window 1933305 sent adjust 102400
debug2: channel 0: window 1413132 sent adjust 102400
debug2: channel 0: window 1155080 sent adjust 102400
debug2: channel 0: window 1093652 sent adjust 102400
debug2: channel 0: window 1083509 sent adjust 102400
debug2: channel 0: window 1083509 sent adjust 102400
debug2: channel 0: window 1171470 sent adjust 102400
debug2: channel 0: window 1273870 sent adjust 102400
debug2: channel 0: window 1376270 sent adjust 102400
debug2: channel 0: window 1478670 sent adjust 102400
debug2: channel 0: window 1581070 sent adjust 102400
debug2: channel 0: window 1683470 sent adjust 102400
debug2: channel 0: window 1785870 sent adjust 102400
debug2: channel 0: window 1888270 sent adjust 102400
debug2: channel 0: window 1990670 sent adjust 102400
debug2: channel 0: window 1972351 sent adjust 36840
debug2: channel 0: window 1998840 sent adjust 98312
debug2: channel 0: window 1935461 sent adjust 102400
debug2: channel 0: window 1859653 sent adjust 102400
debug2: channel 0: window 1962053 sent adjust 102400
debug2: channel 0: window 1875952 sent adjust 102400
debug2: channel 0: window 1875952 sent adjust 102400
debug2: channel 0: window 1978352 sent adjust 102400
debug2: channel 0: window 1978352 sent adjust 102400
debug2: channel 0: window 1994774 sent adjust 49158
debug2: channel 0: window 1978397 sent adjust 118755
debug2: channel 0: window 1998840 sent adjust 86045
debug2: channel 0: window 1986592 sent adjust 110560
debug2: channel 0: window 1998840 sent adjust 61482
debug2: channel 0: window 1994752 sent adjust 102400
debug2: channel 0: window 1994752 sent adjust 102400
debug2: channel 0: window 1994752 sent adjust 102400
debug2: channel 0: window 1994752 sent adjust 102400
debug2: channel 0: window 1994752 sent adjust 102400
debug2: channel 0: window 1994752 sent adjust 102400
debug2: channel 0: window 1994752 sent adjust 102400
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug3: receive packet: type 96
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug2: channel 0: chan_shutdown_read (i0 o1 sock -1 wfd 5 efd 7 [write])
debug2: channel 0: input open -> closed
debug3: channel 0: will not send data after close
debug3: channel 0: will not send data after close
debug2: channel 0: obuf empty
debug2: channel 0: chan_shutdown_write (i3 o1 sock -1 wfd 6 efd 7 [write])
debug2: channel 0: output drain -> closed
debug2: channel 0: almost dead
debug2: channel 0: gc: notify user
debug2: channel 0: gc: user detached
debug2: channel 0: send close
debug3: send packet: type 97
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: client-session, nchannels 1
debug3: channel 0: status: The following connections are open:
  #0 client-session (t4 r43 i3/0 o3/0 e[write]/0 fd -1/-1/7 sock -1 cc -1)

debug3: send packet: type 1
fatal: early EOF
debug3: fd 0 is not O_NONBLOCK
debug3: fd 2 is not O_NONBLOCK
Transferred: sent 5076, received 5604380 bytes, in 1.2 seconds
Bytes per second: sent 4175.1, received 4609725.3
debug1: Exit status 0
fatal: the remote end hung up unexpectedly
fatal: index-pack failed
petemounce commented 5 years ago

@NoMoreFood I think in our case (based on the timestamps in my log above), around 1.1s between running the command in the client and starting to receive data.

analogrelay commented 5 years ago

I get this fairly consistently (but not 100% reliably) when cloning Git repos using Win32 SSH. Most commonly when cloning https://github.com/aspnet/AspNetCore

petemounce commented 5 years ago

We get this around 50% of the time, intermittently. This also happens with OpenSSH 8.0.0.0p1-Beta

NoMoreFood commented 5 years ago

@anurse @petemounce What OSes are you running?

petemounce commented 5 years ago

@NoMoreFood I am running Windows Server 2016 Desktop/GUI edition within Google Cloud. Image Family is windows-2016, specific image at the moment is windows-server-2016-dc-v20190620. The images are regularly changed by Google as patch Tuesdays and other changes happen - if that image is no longer present, it's possible to show deprecated images via the console or a gcloud flag.

If it's relevant, https://github.com/GoogleCloudPlatform/compute-image-windows/ is I think what goes into the image-creation process to prepare them for customer usage.

petemounce commented 5 years ago

This is the script I'm using to bootstrap sshd onto the instances in question - this is relevant to this issue I think because it's how ssh.exe becomes present, and how the default shell is set to powershell.

(The verbatim script relies on GCE-GetMetadata to pull the base64 encoded sshd_config (also snippet'd here) and a base64 encoded public key from GCE instance-metadata. Those sections can be hacked out with hard-coded values if you don't run this within GCE to reproduce; I don't have the Azure/AWS equivalents supported, sorry. I included the full script + sshd_config because I thought you might be interested in adapting it into your docs around enabling pubkey auth - if there's an issue around that, please point me at it and I can replicate there if that's helpful)

bootstrap.ps1

param(
    [string] $username = "different", # This isn't who we use ;)
    [string] $open_ssh_version = "v8.0.0.0p1-Beta"
)
$ErrorActionPreference = 'Stop'; # stop on all errors

Start-Transcript -Path "$($PSScriptRoot)/bootstrap.log" -IncludeInvocationHeader

Write-Output "Make the administrator user for packer: $($username)"
$Count = Get-Random -min 24 -max 32
$TempPassword = -join ((65..90) + (97..122) + (48..57) | Get-Random -Count $Count | % {[char]$_})
New-LocalUser -Name $username -PasswordNeverExpires -Password ($TempPassword | ConvertTo-SecureString -AsPlainText -Force) | out-null
Add-LocalGroupMember -Group "Administrators" -Member $username | out-null

Write-Output "Install openssh..."
# https://github.com/PowerShell/Win32-OpenSSH/wiki/Install-Win32-OpenSSH
$url = "https://github.com/PowerShell/Win32-OpenSSH/releases/download/$($open_ssh_version)/OpenSSH-Win64.zip"
$output = "$($env:TEMP)/OpenSSH-Win64.zip"
# github went TLS 1.2 only from 2018
[System.Net.ServicePointManager]::SecurityProtocol = [System.Net.SecurityProtocolType]::Tls12;
(New-Object System.Net.WebClient).DownloadFile($url, $output)
Expand-Archive -Path $output -DestinationPath "$($env:PROGRAMFILES)"
. "$($env:PROGRAMFILES)/OpenSSH-Win64/install-sshd.ps1"

Write-Output "Set default shell for sshd connections to powershell to avoid legacy cmd nonsense"
# https://github.com/PowerShell/Win32-OpenSSH/wiki/DefaultShell
[System.Environment]::SetEnvironmentVariable("PATH", "$($env:PATH);c:\Program Files\OpenSSH-Win64", [System.EnvironmentVariableTarget]::Machine)
New-Item -path "HKLM:\SOFTWARE\OpenSSH" -force
New-ItemProperty -Path "HKLM:\SOFTWARE\OpenSSH" -Name DefaultShell -Value "C:\Windows\System32\WindowsPowerShell\v1.0\powershell.exe" -PropertyType String -Force
New-ItemProperty -Path "HKLM:\SOFTWARE\OpenSSH" -Name DefaultShellCommandOption -Value "/c" -PropertyType String -Force

Write-Output "Set up sshd_config..."
# An sshd_config that's basically the stock one but
# * allows public key authentication (which is commented by default)
$sshd_config = "$($env:PROGRAMDATA)/ssh"
New-Item "$($sshd_config)" -Type Directory -Force
$sshd_config_file = "$($sshd_config)/sshd_config"
$sshd_config_base64 = get-gcemetadata -path "instance/attributes/imp-sshd-config-base64"
$sshd_config_text = [System.Text.Encoding]::UTF8.GetString([System.Convert]::FromBase64String($sshd_config_base64))
Set-Content -Path "$($sshd_config_file)" -Value "$($sshd_config_text)"

Write-Output "Place public key in system-wide authorized keys..."
# Put the public key in the system-wide config location to avoid needing to programmatically create user profile. Sigh.
$public_key_base64 = get-gcemetadata -path "instance/attributes/imp-public-key-base64"
$public_key = [System.Text.Encoding]::UTF8.GetString([System.Convert]::FromBase64String($public_key_base64))
$system_authorized_keys_file = "$($sshd_config)/administrators_authorized_keys"
if (Test-Path "$($system_authorized_keys_file)") {
  Remove-Item -Path "$($system_authorized_keys_file)" -force
}
Set-Content -Path "$($system_authorized_keys_file)" -Value "$($public_key)"

Write-Output "Ensure access control on authorized_keys meets the requirements..."
# https://stackoverflow.com/questions/16212816/setting-up-openssh-for-windows-using-public-key-authentication
# https://github.com/jen20/packer-aws-windows-ssh/blob/master/files/configure-source-ssh.ps1#L99-L114
$acl = Get-ACL -Path $system_authorized_keys_file
$acl.SetAccessRuleProtection($True, $True)
Set-Acl -Path $system_authorized_keys_file -AclObject $acl
$acl = Get-ACL -Path $system_authorized_keys_file
$ar = New-Object System.Security.AccessControl.FileSystemAccessRule( `
    "NT Authority\Authenticated Users", "ReadAndExecute", "Allow")
$acl.RemoveAccessRule($ar)
$ar = New-Object System.Security.AccessControl.FileSystemAccessRule( `
    "BUILTIN\Administrators", "FullControl", "Allow")
$acl.RemoveAccessRule($ar)
$ar = New-Object System.Security.AccessControl.FileSystemAccessRule( `
    "BUILTIN\Users", "FullControl", "Allow")
$acl.RemoveAccessRule($ar)
Set-Acl -Path $system_authorized_keys_file -AclObject $acl

Write-Output "Restart sshd..."
Restart-Service sshd
Set-Service sshd -StartupType Automatic

Write-Output "Open up the firewall port for ssh"
New-NetFirewallRule -Name sshd -DisplayName 'OpenSSH Server (sshd)' -Enabled True -Direction Inbound -Protocol TCP -Action Allow -LocalPort 22

Write-Output "NGEN powershell assembly, improves startup time of powershell by 10x"
$env:path = [Runtime.InteropServices.RuntimeEnvironment]::GetRuntimeDirectory()
[AppDomain]::CurrentDomain.GetAssemblies() | % {
  if (! $_.location) {continue}
  $Name = Split-Path $_.location -leaf
  if ($Name.startswith("Microsoft.PowerShell.")) {
    Write-Host -ForegroundColor Yellow "NGENing : $Name"
    ngen install $_.location | % {"`t$_"}
  }
}

Write-Output "Done."
Stop-Transcript

sshd_config

Port 22
# Logging
#SyslogFacility AUTH
#LogLevel INFO

# Authentication:

#LoginGraceTime 2m
#PermitRootLogin prohibit-password
#StrictModes yes
#MaxAuthTries 6
#MaxSessions 10

PubkeyAuthentication yes

# The default is to check both .ssh/authorized_keys and .ssh/authorized_keys2
# but this is overridden so installations will only check .ssh/authorized_keys
AuthorizedKeysFile  .ssh/authorized_keys

PasswordAuthentication no
PermitEmptyPasswords no

TCPKeepAlive yes
ClientAliveInterval 300
ClientAliveCountMax 10

# override default of no subsystems
Subsystem   sftp    sftp-server.exe

Match Group administrators
    AuthorizedKeysFile __PROGRAMDATA__/ssh/administrators_authorized_keys
analogrelay commented 5 years ago

@anurse @petemounce What OSes are you running?

Windows 10 (various builds, including 18932.1000). Just a standard interactive instance (no docker containers, etc.). Literally just tried and got it again:

cmd /c ver

Microsoft Windows [Version 10.0.18932.1000]

git clone git@github.com:aspnet/AspNetCore.git ANCTest1

Cloning into 'ANCTest1'...
Enter passphrase for key 'C:\Users\anurse/.ssh/id_rsa':
remote: Enumerating objects: 44, done.
remote: Counting objects: 100% (44/44), done.
remote: Compressing objects: 100% (43/43), done.
fatal: The remote end hung up unexpectedly77.63 MiB | 19.90 MiB/s
fatal: early EOF
fatal: index-pack failed

Get-Command ssh

C:\Windows\System32\OpenSSH\ssh.exe

$env:GIT_SSH

C:\Windows\System32\OpenSSH\ssh.exe

C:\Windows\System32\OpenSSH\ssh.exe -V

OpenSSH_for_Windows_7.7p1, LibreSSL 2.6.5

git clone git@github.com:aspnet/AspNetCore.git ANCTest With GIT_SSH_COMMAND=C:\\Windows\\System32\\OpenSSH\\ssh.exe -vvv

clone.log

analogrelay commented 5 years ago

It's not a 100% consistent repro for me, but it's like.. 80-90% consistent. I can usually get a successful clone by repeating a bunch of times. Alternately, if I reset git to use it's built-in build of ssh (OpenSSH_7.7p1, OpenSSL 1.0.2o 27 Mar 2018) then it clones successfully every time.

petemounce commented 5 years ago

I badly don't want to use the ssh bundled with git-for-windows because then I (I think?) would need to find a different arrangement for auth, differently from the other two platforms I support.

I think my options would be:

petemounce commented 5 years ago

@NoMoreFood friendly ping? Is there any more information I could provide that might help?

RNabel commented 5 years ago

@NoMoreFood Running into this on Windows Server 2019 as well (OpenSSH version 7.7.2.1 from Windows Update / pre-installed with Windows). Is there a timeline on addressing this?

NoMoreFood commented 5 years ago

@petemounce @RNabel I've been working on other projects, but might be able to sneak this in. Can you verify it's still reproducible on 8.0?

petemounce commented 5 years ago

It's definitely still reproducible on 8. I'm less sure it's a data problem, since on retry it can succeed against the same sha being cloned.

333fred commented 5 years ago

I see this all the time when attempting to clone dotnet/roslyn with 7.7.2.1. It's getting to the point that I'm going to have to disable the service.

petemounce commented 4 years ago

@NoMoreFood friendly ping? Any news?

333fred commented 4 years ago

If you need a repo that commonly reproduces this, try cloning https://github.com/dotnet/roslyn. It's a pretty reliable failure for me.

goldstar611 commented 4 years ago

I also consistently get this on Windows 10 when running git clone <<any repo>> over a SSH connection. Even doing ssh localhost before running git clone causes failures described here

petemounce commented 4 years ago

@NoMoreFood do you need any more information for repro, or want any other help?

asherccohen commented 4 years ago

Any news on this?I'm seeing the same behaviour...

vvuk commented 4 years ago

This seemed to be much better once I moved to OpenSSH_for_Windows_8.0p1 but now I'm back to seeing it all the time.

analogrelay commented 4 years ago

Still happening in OpenSSH_for_Windows_8.1p1, LibreSSL 2.9.2 :(. This is really blocking my ability to use the Windows OpenSSH client since I basically can't clone any of the Git repos I work with using it.

knolleCC commented 4 years ago

Same problem here. I have a repo with a lot of data inside which fails to be cloned 100% of the time with the mentioned error. Since using the Windows SSH Agent in general is very comfortable, a solution for this would be very much appreciated.

seritools commented 4 years ago

Still happening on 19569. :(

benpapworth commented 4 years ago

I have observed this issue on Anaconda OpenSSH build of git too: git 2.19.1 has ssh ‘OpenSSH_7.7p1, OpenSSL 1.0.2p 14 Aug 2018’ and always works. git 2.20.1 has ssh ‘OpenSSH_7.9p1, OpenSSL 1.1.1a 20 Nov 2018’ and always fails with Fatal early EOF.

So a change was introduced between these two versions that broke git over SSH. :(

Yanivkoval commented 4 years ago

The issue still exists. What I observed is that ssh.exe exits or crashes for no apparent reason in the middle of an operation.

Therfore results in fatal: the remote end hung up unexpectedly fatal: early EOF fatal: index-pack failed

Try running: ssh.exe -vT git@github.com and you will see that it exists or crashes before it completes the operation, right after the

"Are you sure you want to continue connecting (yes/no)?"

For me it is static 2~5 second. and it returns back to shell.

Version 7.7, on the other hand, doesn't do that and works as intended.

OS: Windows 10 1809 17763.973

beppler commented 4 years ago

I have the issue too. In one computer it always works and on another run clone almost always result in error (sometimes it works).

Both computers have these versions:

The only difference is that one of them is running windows professional (where it works) and the other is running windows enterprise.

On the computer that is getting errors the following log is generated (I included only the begging and the end of the log):

PS> git clone -v git@git.mps.com.br:gti/gerente-seguranca.git
09:06:43.071921 exec-cmd.c:237          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
09:06:43.071921 git.c:439               trace: built-in: git clone -v git@git.mps.com.br:gti/gerente-seguranca.git
Cloning into 'gerente-seguranca'...
09:06:43.087545 run-command.c:663       trace: run_command: unset GIT_DIR; GIT_PROTOCOL=version=2 C:/Local/OpenSSH-Win64/ssh.exe -o SendEnv=GIT_PROTOCOL git@git.mps.com.br 'git-upload-pack '\''gti/gerente-seguranca.git'\'''
09:06:43.400064 pkt-line.c:80           packet:        clone< 49bdf0b27e8f9f99f58d5866b5e22a8765a69dfb HEAD\0multi_ack thin-pack side-band side-band-64k ofs-delta shallow deepen-since deepen-not deepen-relative no-progress include-tag multi_ack_detailed symref=HEAD:refs/heads/master agent=git/2.20.1
...
09:06:43.712532 pkt-line.c:80           packet:     sideband< \2Compressing objects: 100% (2567/2567)   \15
09:06:43.712532 pkt-line.c:80           packet:     sideband< \2Compressing objects: 100% (2567/2567), done.
remote: Compressing objects: 100% (2567/2567), done.
09:06:43.712532 pkt-line.c:80           packet:     sideband< PACK ...
fatal: the remote end hung up unexpectedly4 MiB | 18.05 MiB/s
fatal: early EOF
fatal: index-pack failed

PS: using the git bundled ssh (OpenSSH_8.2p1, OpenSSL 1.1.1f 31 Mar 2020) it always work, but using it make the ssh-agent use very hard.

knolleCC commented 4 years ago

In our company we recently observed that using git protocol v2 on both client and server seems to improve the issue. We have a big repo which nearly always produces the error on clone. With git protocol v2 it suddenly always works.

@beppler I see in your log that your already use protocol v2 so apparently the problem is not always solved through this. However, at our site it works.

beppler commented 4 years ago

More information.

If i set GIT_SSH_COMMAND to C:/Local/OpenSSH-Win64/ssh.exe -vvv to enable SSH logging, it almost always works.

dscho commented 4 years ago

Hi, Yes, of course. That's where I got the '-vvv' to try.

If I unset my normal ssh config, I will have to migrate the pertinent keys (and figure how to set up key-agent again, maybe), so that will not be today.

Best, G.

$ git clone --recursive ssh://git@gitlab.cern.ch:7999/tdr/papers/TOP-18-013 16:12:19.936320 exec-cmd.c:237 trace: resolved executable dir: H:/GitTest/PortableGit_2_28_0_pristine/mingw64/bin 16:12:19.937319 git.c:444 trace: built-in: git clone --recursive ssh://git@gitlab.cern.ch:7999/tdr/papers/TOP-18-013 Cloning into 'TOP-18-013'... 16:12:19.985287 run-command.c:663 trace: run_command: unset GIT_DIR; ssh -p 7999 git@gitlab.cern.ch 'git-upload-pack '''/tdr/papers/TOP-18-013'''' git@gitlab.cern.ch: Permission denied (publickey). fatal: Could not read from remote repository.

@georgealverson are you sure you replied to the correct ticket? I think you meant to reply in this ticket instead...

jhenkens commented 4 years ago

In our company we recently observed that using git protocol v2 on both client and server seems to improve the issue. We have a big repo which nearly always produces the error on clone. With git protocol v2 it suddenly always works.

Writing on behalf off git users at the company I work for. We primarily use Gitlab, and had been seeing EOF issues on all repositories, small and large, for the past 6-12 months or so. It is much more common on large repos, presumably because they take longer to fetch/clone! All of our users use git+ssh to connect. The issue was only a problem for Windows users.

We found this advice to try git protocol v2, and implemented it mid last week for a test group, after enabling it on the server level. The issue has gone away for the test group. Just thought I'd share our results after about a week of testing.

Zenexer commented 3 years ago

Any progress on this? It's been an issue for over a year now. MSDN's own docs encourage using the built-in ssh-agent, but combining that with git causes this error pretty reliably.

kirksaunders commented 3 years ago

I was consistently encountering this error, but I haven't gotten it since I manually upgraded to the latest (v8.1.0.0p1-Beta) release. If anyone encountering this issue is running an older version, you may have some success upgrading to the latest.

kstrophus commented 3 years ago

@kirksaunders I uninstalled the default Windows 10 OpenSSH client and manually installed v8.1.0.0p1-Beta (still the current latest), and the issue persists for me.

ssh -V OpenSSH_for_Windows_8.1p1, LibreSSL 2.9.2

kirksaunders commented 3 years ago

@kstrophus That's what worked for me. Apologies that you didn't have the same luck; unfortunately I have no other advice.

mgkuhn commented 3 years ago

Does this issue persist with the “OpenSSH version in Windows Features”, which is now 8.1 as of this week (install KB5003173 via Windows Update on the Semi-Annual Channel)? You'll need Windows 10/Server 1903 or newer (i.e., not LTSC versions).

bagajjal commented 3 years ago

Closing this issue as its fixed in V8.1

Cu3PO42 commented 3 years ago

I am still experiencing this problem. It happens primarily with large repositories. Passing --depth 1 to clone fixes the problem (I assume because the amount to be transferred decreases), but a subsequent unshallow will fail.

I have a Windows 10 20H2 install and can reproduce this with both Git for Windows 2.29.0 and Git 2.32.0 in MSYS2. Mỳ OpenSSH version is 8.1.0.1. I have tried upgrading to the v8.6 beta version manually, but this did unfortunately not fix the issue either.

The clone works fine if I unset core.sshCommand and let Git for Windows use its own, but this breaks my authentication workflow, sadly. I tried setting SSH_AUTH_SOCK so that Git for Windows' SSH would use Windows' SSH Agent, but it appears this does not work. I'm assuming this version of SSH does not deal with Windows' named pipes.

r0nw commented 2 years ago

I am also still experiencing this issue (with both 8.1 and 8.6), apparently it's not fixed.

I can easily reproduce it with any larger repo locally, as well as with the AspNetCore repo at github as was noted above (happened 3 times out of 3 attempts).

So can this get reopened at least, please? Or should we file new issue?

mgkuhn commented 2 years ago

I'd file a new issue with detailed instructions on how anyone could reproduce this problem with little effort. (Mention this issue as related, so it gets cross-referenced.)

In particular, in your new issue, please provide a specific commit in a specific git repository, and document exactly which ssh and git versions you used and what the error message is. Basically, provide an exact set of command-lines (or a script) that we all can run in a fresh VM of Windows 10 21H1 such that we will very likely encounter the exact same error as you.

An easily reproducible example is a prerequisite for any meaningful debugging effort. A minimal example would be best.

r0nw commented 2 years ago

An easily reproducible example is a prerequisite for any meaningful debugging effort. A minimal example would be best.

@mgkuhn Well, sure, but here I've just used the very simple repro step from this issue, as mentioned in multiple comments above, which is git clone git@github.com:aspnet/AspNetCore.git (with core.sshCommand pointing to the win32 ssh binary, obviously), so it's not that I would be reporting something new without providing relevant details.

Yesterday when I was trying with cloning this repo from github, the issue happened 3 times out of 3 attempts, so it seemed like very easily reproducible. However now I tried again, reproduced it again on 1st attempt, but then I needed 8 subsequent attempts to repro it again, so it's not that easy after all. But still quite easy.

This issue was closed as fixed without linking any particular fix, and despite multiple people writing here even before that they still have the problem even with the 8.1 version (and 8.6 too, as reported later, again by multiple people already).

dscho commented 2 years ago

@r0nw the reproducer you used might be good enough to demonstrate the issue, but you are asking others to debug and fix the issue, and for that scenario, a flake that does not even reproduce 8 times in a row is not good enough. Besides, you will want to offer a reproducer that reproduces the issue as quickly as possible, and without involving two processes where the first one spawns the one you actually want to debug.

If you want to see progress on this issue, the best bet you got is really to simplify the reproducer so as to make the (still quite involved and cumbersome) task of debugging it much less tedious. Otherwise you will leave even that part to others, and that's just a recipe for being put on the backburner.

mgkuhn commented 2 years ago

What might be useful is a simple test harness (e.g. a Perl or Python script) that exercises ssh in the same way as Git for Windows does. I presume this involves sending a large amount of binary data through ssh via stdin/stdout. What can go wrong there? Any of the usual binary-transparency pitfalls of terminal communication, e.g. ASCII control characters, such as XON/XOFF or CR/LF or Ctrl-Z/D or NUL (see #1842) or BS/DEL getting interpreted/substituted at some level? Is it something specific to git, or is git just one example application that sends a particularly large amount of binary data via stdin/stdout through ssh? Perhaps it happens only if the problematic byte appears in a particular location in a buffer?

r0nw commented 2 years ago

I have very quickly looked at the communication at network level (TCP packets), and while I don't see any conclusive difference between the failed and successful cases, I do see an interesting difference between the win32 ssh and the msys one provided by git-for-windows. While with msys ssh it ends cleanly (client sends FIN, server acks, server sends FIN, client acks), with the win32 ssh it ends abruptly (by client sending RST), both in successful and failed case. So I'd guess there is an issue with closing the socket forcefully instead of doing proper shutdown.

Btw, I don't have any strong motivation to have this fixed, I was just checking whether this win32 ssh is already mature enough to use it, and stumbled upon this issue, which apparently is not fixed although marked as such, so I have just reported here. I'm not really ready to spend too much time finding better repro steps. I find the repro steps mentioned (just clone the AspNetCore repo from github repeatedly) actually quite good (sure 100% repro would be better, but I don't have that either).

NicolasRouquette commented 2 years ago

I am also experiencing this problem with Windows 10 Enterprise (OS Build 19043.1288) and our Github Enterprise installation.

Fortunately, I managed to work around this problem by performing equivalent operations in WSL2/ubuntu 20.04 instead of Windows. Same machine, same Full VPN network.

On Windows: git version 2.33.0.windows.2 OpenSSH_for_Windows_8.1p1, LibreSSL 3.0.2

On Ubuntu: git version 2.25.1 OpenSSH_8.2p1 Ubuntu-4ubuntu0.3, OpenSSL 1.1.1f 31 Mar 2020

Hnasar commented 2 years ago

This bug is not fixed. @bagajjal you made a mistake in closing this.

KorkyPlunger commented 2 years ago

I was also having the exact same issue with OpenSSH for windows v8.1.0.1 (the version build into Win 10 currently). Switching to the latest release of Win32-OpenSSH (v 8.6.0) fixed it in some cases but not others.

Here's a snippet of output using v8.1.0.1, with core.sshCommand in .gitconfig set to 'C:\\Windows\\System32\\OpenSSH\\ssh.exe' -vvv. You can see the failure at the end:

~\dev\G3 [dev-vs2022]> git fetch
OpenSSH_for_Windows_8.1p1, LibreSSL 3.0.2
<...snip...>
debug1: Sending command: git-upload-pack '/projects/G3'
debug2: channel 0: request exec confirm 1
debug3: send packet: type 98
debug2: channel_input_open_confirmation: channel 0: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel 0: rcvd adjust 2097152
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: exec request accepted on channel 0
debug2: channel 0: window 1974603 sent adjust 122549
remote: Counting objects: 735, done.
remote: Compressing objects: 100% (266/266), done.
debug3: receive packet: type 96
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype eow@openssh.com reply 0
debug2: channel 0: rcvd eow
debug2: channel 0: chan_shutdown_read (i0 o1 sock -1 wfd 4 efd 6 [write])
debug2: channel 0: input open -> closed
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug3: channel 0: will not send data after close
debug2: channel 0: obuf empty90)
debug2: channel 0: chan_shutdown_write (i3 o1 sock -1 wfd 5 efd 6 [write])
fetch-pack: unexpected disconnect while reading sideband packet
fatal: early EOF

I then

  1. installed Win32-OpenSSH V8.6.0.0p1-Beta from https://github.com/PowerShell/Win32-OpenSSH/releases
  2. changed core.sshCommand in .gitconfig set to 'C:\\dev\\bin\\OpenSSH-Win64\\ssh.exe' -vvv so it pointed to this manual install

I ran the fetch again, and it worked

~\dev\G3-B [master]> git fetch
OpenSSH_for_Windows_8.6p1, LibreSSL 3.3.3
<...snip...>
debug1: Sending command: git-upload-pack '/projects/G3'
debug2: channel 0: request exec confirm 1
debug3: send packet: type 98
debug2: channel_input_open_confirmation: channel 0: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel 0: rcvd adjust 2097152
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: exec request accepted on channel 0
debug2: channel 0: window 1997432 sent adjust 99720
remote: Counting objects: 744, done.
remote: Compressing objects: 100% (274/274), done.
debug3: receive packet: type 96
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype eow@openssh.com reply 0
debug2: channel 0: rcvd eow
debug2: chan_shutdown_read: channel 0: (i0 o1 sock -1 wfd 4 efd 6 [write])
debug2: channel 0: input open -> closed
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug3: channel 0: will not send data after close
debug2: channel 0: obuf empty99)
Receivingdebug2: chan_shutdown_write: channel 0: (i3 o1 sock -1 wfd 5 efd 6 [write])
debug2: channel 0: output drain -> closed
debug2: channel 0: almost dead99)
debug2: channel 0: gc: notify user
remote: Total 299 (delta 214), reused 0 (delta 0)
debug2: channel 0: send close299)

debug3: send packet: type 97/299)
debug2: channel 0: is dead94/299)
Receiving objects: 100% (299/299), 47.83 KiB | 1.99 MiB/s, done.
debug2: channel 0: garbage collecting
Rdebug1: channel 0: free: client-session, nchannels 1
debug3: channel 0: status: The following connections are open:
  #0 client-session (t4 r0 i3/0 o3/0 e[write]/0 fd -1/-1/6 sock -1 cc -1)

Rdebug3: send packet: type 1
debug3: fd 0 is not O_NONBLOCK
Transferred: sent 5480, received 235232 bytes, in 1.0 seconds
Bytes per second: sent 5300.0, received 227505.2
debug1: Exit status 0
Resolving deltas: 100% (214/214), completed with 96 local objects.

However, on another repository, the switch to the new version of SSH did not fix it by itself. On this repo (which is a different clone of the same repo as above, just in a different location), I had to:

  1. Do a fetchl using the newer version of OpenSSH. This failed with the same Unexpected EOF
  2. Change core.compression from 9 to 0 in my .gitconfig
  3. Fetch again. This also failed for the same reason
  4. Delete core.compression from my .gitconfig.
  5. Fetch again. This then succeeded

I have no explanation for what's going on here, only that something is still very wrong.

This issue should be re-opened.

Hnasar commented 2 years ago

Agreed this needs to be reopened. We finally found a workaround: stop using Win32-OpenSSH! The ssh bundled with git for windows seems to not have this problem. It's a bit more picky with only wanting unix style line endings in your keyfiles but apart from that it's great. I wish I never spent so much time with this program considering this bug is not fixed.