Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

x/crypto/ssh: ssh: handshake failed: ssh: unexpected message type 3 (expected one of [6]) #18861

Closed
lucaswxp opened this issue Jan 31, 2017 · 35 comments
Assignees
Milestone

Comments

@lucaswxp
Copy link

@lucaswxp lucaswxp commented Jan 31, 2017

What version of Go are you using (go version)?

go version go1.7.4 darwin/amd64

What operating system and processor architecture are you using (go env)?

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/lucaswxp"
GORACE=""
GOROOT="/usr/local/go"
GOTOOLDIR="/usr/local/go/pkg/tool/darwin_amd64"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/mw/y5nw62813y9105dl9n5wy6_40000gn/T/go-build710665517=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"

What did you do?

Tried creating a SSH client:

  c := &ssh.ClientConfig{User:"a",Auth:[]ssh.AuthMethod{ssh.Password("b")}}
  _, err := ssh.Dial("tcp", "x.x.x.x:22", c)

  if err != nil {
    fmt.Printf("%s", err)
 }

What did you expect to see?

Successful login. I can login in terminal, but any host I put in .Dial() I get the following error:

What did you see instead?

ssh: handshake failed: ssh: unexpected message type 3 (expected one of [6])

What is type 3 error? Any host I put I get this message.

@mblair
Copy link

@mblair mblair commented Jan 31, 2017

I'm hitting this too. I've done a little bisecting, and it looks like this is the offending commit:

golang/crypto@a59c127

@hanwen

@hanwen
Copy link
Contributor

@hanwen hanwen commented Jan 31, 2017

const msgUnimplemented = 3
const msgServiceAccept = 6

what does the remote end run?

Can you run with debugHandshake and post the log output?

@hanwen
Copy link
Contributor

@hanwen hanwen commented Jan 31, 2017

oh, I can see this on tests against openssh. Investigating.

@zcalusic
Copy link

@zcalusic zcalusic commented Jan 31, 2017

Hitting this bug, too. go1.8rc3 linux/amd64

Tnx for looking into it.

@tarys-db
Copy link

@tarys-db tarys-db commented Jan 31, 2017

The bug was also present in 1.7.1.
I upgraded to 1.7.5 and it's still there.
To me it happens randomly (more often than not) when using "PublicKeys" auth.

@hanwen
Copy link
Contributor

@hanwen hanwen commented Jan 31, 2017

the Go version is probably irrelevant. This must be related to the recent changes in the SSH code.

@tarys-db
Copy link

@tarys-db tarys-db commented Jan 31, 2017

Here is a debug output of a failed connection. Maybe that helps.

debug2: load_server_config: filename /etc/ssh/sshd_config
debug2: load_server_config: done config len = 837
debug2: parse_server_config: config /etc/ssh/sshd_config len 837
debug1: sshd version OpenSSH_6.9, OpenSSL 1.0.2d 9 Jul 2015
debug1: private host key #0: ssh-rsa SHA256:---
debug1: private host key #1: ssh-dss SHA256::---
debug1: private host key #2: ecdsa-sha2-nistp256 SHA256:---
debug1: private host key #3: ssh-ed25519 SHA256::---
debug1: rexec_argv[0]='/usr/sbin/sshd'
debug1: rexec_argv[1]='-p'
debug1: rexec_argv[2]='22222'
debug1: rexec_argv[3]='-D'
debug1: rexec_argv[4]='-dd'
debug1: rexec_argv[5]='-e'
Set /proc/self/oom_score_adj from 0 to -1000
debug2: fd 3 setting O_NONBLOCK
debug1: Bind to port 22222 on 0.0.0.0.
Server listening on 0.0.0.0 port 22222.
debug2: fd 4 setting O_NONBLOCK
debug1: Bind to port 22222 on ::.
Server listening on :: port 22222.
debug1: Server will not fork when running in debugging mode.
debug1: rexec start in 5 out 5 newsock 5 pipe -1 sock 8
debug2: parse_server_config: config rexec len 837
debug1: sshd version OpenSSH_6.9, OpenSSL 1.0.2d 9 Jul 2015
debug1: private host key #0: ssh-rsa SHA256:---
debug1: private host key #1: ssh-dss SHA256:---
debug1: private host key #2: ecdsa-sha2-nistp256 SHA256:/---
debug1: private host key #3: ssh-ed25519 SHA256:/---
debug1: inetd sockets after dupping: 3, 3
Connection from 123.123.123.123 port 44694 on 172.31.1.100 port 22222
debug1: Client protocol version 2.0; client software version Go
debug1: no match: Go
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.9p1 Ubuntu-2ubuntu0.2
debug2: fd 3 setting O_NONBLOCK
debug2: Network child is on pid 14539
debug1: permanently_set_uid: 107/65534 [preauth]
debug1: list_hostkey_types: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug1: SSH2_MSG_KEXINIT sent [preauth]
debug1: SSH2_MSG_KEXINIT received [preauth]
debug2: kex_parse_kexinit: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha1 [preauth]
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
debug2: kex_parse_kexinit: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
debug2: kex_parse_kexinit: 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 [preauth]
debug2: kex_parse_kexinit: 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 [preauth]
debug2: kex_parse_kexinit: none,zlib@openssh.com [preauth]
debug2: kex_parse_kexinit: none,zlib@openssh.com [preauth]
debug2: kex_parse_kexinit: [preauth]
debug2: kex_parse_kexinit: [preauth]
debug2: kex_parse_kexinit: first_kex_follows 0 [preauth]
debug2: kex_parse_kexinit: reserved 0 [preauth]
debug2: kex_parse_kexinit: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1 [preauth]
debug2: kex_parse_kexinit: ssh-rsa-cert-v01@openssh.com,ssh-dss-cert-v01@openssh.com,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-rsa,ssh-dss,ssh-ed25519 [preauth]
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,arcfour256,arcfour128 [preauth]
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,arcfour256,arcfour128 [preauth]
debug2: kex_parse_kexinit: hmac-sha2-256,hmac-sha1,hmac-sha1-96 [preauth]
debug2: kex_parse_kexinit: hmac-sha2-256,hmac-sha1,hmac-sha1-96 [preauth]
debug2: kex_parse_kexinit: none [preauth]
debug2: kex_parse_kexinit: none [preauth]
debug2: kex_parse_kexinit: [preauth]
debug2: kex_parse_kexinit: [preauth]
debug2: kex_parse_kexinit: first_kex_follows 0 [preauth]
debug2: kex_parse_kexinit: reserved 0 [preauth]
debug1: kex: client->server aes128-ctr hmac-sha2-256 none [preauth]
debug1: kex: server->client aes128-ctr hmac-sha2-256 none [preauth]
debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
debug2: monitor_read: 6 used once, disabling now
debug2: set_newkeys: mode 1 [preauth]
debug1: SSH2_MSG_NEWKEYS sent [preauth]
debug1: expecting SSH2_MSG_NEWKEYS [preauth]
debug2: set_newkeys: mode 0 [preauth]
debug1: SSH2_MSG_NEWKEYS received [preauth]
debug1: KEX done [preauth]
dispatch_protocol_error: type 20 seq 3 [preauth]
Connection closed by 123.123.123.123 [preauth]
debug1: do_cleanup [preauth]
debug1: monitor_read_log: child log fd closed
debug1: do_cleanup
debug1: Killing privsep child 14539
debug1: audit_event: unhandled event 12
<

@hanwen
Copy link
Contributor

@hanwen hanwen commented Jan 31, 2017

can people try out https://go-review.googlesource.com/c/36055/1 to see if that fixes things?

@mblair
Copy link

@mblair mblair commented Jan 31, 2017

@hanwen yep, that fixes things for me.

@stayclassychicago
Copy link

@stayclassychicago stayclassychicago commented Jan 31, 2017

@hanwen ditto, fixes my issues too, consistent connections

@zcalusic
Copy link

@zcalusic zcalusic commented Jan 31, 2017

Works fine here now, thank you @hanwen for your work!

@lucaswxp
Copy link
Author

@lucaswxp lucaswxp commented Jan 31, 2017

Hey guys, sorry, noob question here:
I should git clone the master and compile from source to get the patch?

Regards

@zcalusic
Copy link

@zcalusic zcalusic commented Jan 31, 2017

I was perplexed for a while, so I see where you're coming from. :)

On the right side of https://go-review.googlesource.com/c/36055/1 there's a download button. It saves a complete junk, which you can decode with base64 -d command. After that go to your $GOPATH/golang.org/x/crypto folder and apply what you got from base64 utility with patch -p1 < ssh-patch.diff and finally recompile the utility which uses the library.

Yeah, too complicated IMHO, that gerrit tool not very user friendly, it seems.

@lucaswxp
Copy link
Author

@lucaswxp lucaswxp commented Jan 31, 2017

@zcalusic Ahh, that worked! Thanks, solved for me.

@eikenb
Copy link

@eikenb eikenb commented Feb 1, 2017

I just ran into this to in the sftp package. It was triggering multiple integration tests to fail. I bisected it to the same commit (a59c127) and then found this ticket. I tried your commit and it fixed it for me as well.

@hanwen
Copy link
Contributor

@hanwen hanwen commented Feb 1, 2017

you can fetch the change by doing:

git fetch https://go.googlesource.com/crypto refs/changes/55/36055/1 && git checkout FETCH_HEAD

@CameronGo
Copy link

@CameronGo CameronGo commented Feb 3, 2017

I've temporarily added @hanwen 's step above to my build script and that has solved the problem for me pending a permanent fix

@edmwagner
Copy link

@edmwagner edmwagner commented Feb 3, 2017

This started occurring after a few runs successfully runs via my ide(intellij) and by hand. Found this and reviewed/applied the patch for local builds. Thus far, the issue looks to have been resolved.

I will update if I see the issue again today with the patch in place.

Thank you for finding and working on this so quickly.

yobert pushed a commit to yobert/crypto that referenced this issue Feb 4, 2017
golang/go#18861

Forking for now until it's in master
@yobert
Copy link

@yobert yobert commented Feb 4, 2017

I also hit this issue and the patch fixed it. Thanks!

If anyone wants--- I've got a temporary fork of x/crypto master with the patch applied, until it gets into master. Here -> https://github.com/yobert/crypto

eikenb added a commit to pkg/sftp that referenced this issue Feb 5, 2017
This pulls the fix into travis build to tests can continue while they
get this bug merged upstream.

golang/go#18861
eikenb added a commit to pkg/sftp that referenced this issue Feb 5, 2017
This pulls the fix into travis build to tests can continue while they
get this bug merged upstream.

golang/go#18861
eikenb added a commit to pkg/sftp that referenced this issue Feb 5, 2017
This pulls the fix into travis build to tests can continue while they
get this bug merged upstream.

golang/go#18861
eikenb added a commit to pkg/sftp that referenced this issue Feb 5, 2017
This pulls the fix into travis build to tests can continue while they
get this bug merged upstream.

golang/go#18861
eikenb added a commit to pkg/sftp that referenced this issue Feb 5, 2017
This pulls the fix into travis build to tests can continue while they
get this bug merged upstream. Once merged this should be reverted.

golang/go#18861
@hanwen
Copy link
Contributor

@hanwen hanwen commented Feb 6, 2017

this is now submitted. Can y'all try out https://go.googlesource.com/crypto/+/77014cf7f9bde4925afeed52b7bf676d5f5b4285 and see if it fixes things for you?

@hiroakis
Copy link

@hiroakis hiroakis commented Feb 6, 2017

I was hitting this. It works now after applying the patch.

@zcalusic
Copy link

@zcalusic zcalusic commented Feb 6, 2017

Works fine here. 👍

@eikenb
Copy link

@eikenb eikenb commented Feb 6, 2017

Fixed it for me. Thanks.

@unclejack
Copy link
Contributor

@unclejack unclejack commented Feb 7, 2017

Does the crypto repository have any kind of CI? It seems this could have been discovered automatically by CI.

@bradfitz
Copy link
Contributor

@bradfitz bradfitz commented Feb 7, 2017

@unclejack, it does. See https://build.golang.org/ at the bottom.

But that doesn't mean that the ssh package has perfect test coverage.

@CameronGo
Copy link

@CameronGo CameronGo commented Feb 8, 2017

Hmm - is this really merged to master so that a go get golang.org/x/crypto/ssh would retrieve this fix? I ask b/c I re-ran my build scripts yesterday and my nightly batch processes still failed with this error?

@bradfitz bradfitz added this to the Unreleased milestone Feb 8, 2017
@databus23
Copy link

@databus23 databus23 commented Feb 8, 2017

@unclejack The supposed fix golang/crypto@77014cf is in master for 2 days and seems to be working for a lot of people (including me). Are you sure your tests used the latest master?

@hanwen
Copy link
Contributor

@hanwen hanwen commented Feb 8, 2017

@bradfitz - see

https://go.googlesource.com/crypto/+/ed03dad8de553b023b198606d52b6d968ad57b39

it would be great if these tests could run a couple of select platforms, such as linux.

@CameronGo did you supply -u to "go get" ?

@hanwen
Copy link
Contributor

@hanwen hanwen commented Feb 8, 2017

@unclejack - there are extensive unittests. Unfortunately, this issue is very sensitive to timing and scheduling. If you know of a way to exercise all the different orderings in which events can happen, let us know.

@unclejack
Copy link
Contributor

@unclejack unclejack commented Feb 8, 2017

@bradfitz @hanwen I'll try to come up with a test for this issue. The ssh package is critical in the context of a project. That's the reason why I've asked that question above. I didn't get a chance to try it out after the fix was merged.

I'll send a CL once that test is ready.

@CameronGo
Copy link

@CameronGo CameronGo commented Feb 8, 2017

@hanwen - my jenkins scripts use the docker golang images, so the GOHOME is always empty when it launches, so the packages always get pulled. Still, I triggered another rebuild yesterday and my batch processes last night did not encounter any errors, so I'll keep an eye on it for the next couple of days, but I'm in good shape right now.

@yobert
Copy link

@yobert yobert commented Feb 17, 2017

If this helps anyone trying to write a test case--- I didn't get this error until I started using an encrypted key via SSH agent. Loading the same key (but unencrypted) directly from disk worked just fine.

@hanwen
Copy link
Contributor

@hanwen hanwen commented Mar 13, 2017

This issue is fixed, so closing this bug.

@hanwen hanwen closed this Mar 13, 2017
@simon-s9
Copy link

@simon-s9 simon-s9 commented Mar 13, 2017

When will this get to stable release? I'm on latest 1.8 (from golang.org) and the issue is still here.

@bradfitz
Copy link
Contributor

@bradfitz bradfitz commented Mar 13, 2017

@simon-s9, the "ssh" package is not part of the Go standard library, so whether you're on Go 1.8 or Go 1.6 is irrelevant. You just need to "go get -u" update the package.

sarahhodne added a commit to travis-ci/worker that referenced this issue Mar 15, 2017
This pulls in a fix for golang/go#18861.

Fixes #290.
sarahhodne added a commit to travis-ci/worker that referenced this issue Mar 21, 2017
@golang golang locked and limited conversation to collaborators Mar 13, 2018
FiloSottile pushed a commit to FiloSottile/go that referenced this issue Nov 24, 2019
The previous attempt would fail in the following scenario:

* select picks "first" kex from requestKex

* read loop receives a remote kex, posts on requestKex (which is now
  empty) [*] for sending out a response, and sends pendingKex on startKex.

* select picks pendingKex from startKex, and proceeds to run the key
  exchange.

* the posting on requestKex in [*] now triggers a second key exchange.

Fixes golang#18861. 

Change-Id: I443e82f1d04c7f17d1485fdb87072b9feec26aa8
Reviewed-on: https://go-review.googlesource.com/36055
Run-TryBot: Han-Wen Nienhuys <hanwen@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Han-Wen Nienhuys <hanwen@google.com>
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
You can’t perform that action at this time.