Fwd: [crypto] ssh: schedule mandatory initial kex with a separate channel

[Han-Wen Nienhuys]

for some reason, this times out on Windows. Would it be possible to
get a goroutine dump of the hang?


---------- Forwarded message ----------
From: Gobot Gobot (Gerrit)
<noreply-gerritcoderevie...@google.com>
Date: Thu, Apr 13, 2017 at 1:51 PM
Subject: [crypto] ssh: schedule mandatory initial kex with a separate channel
To: Han-Wen Nienhuys <han...@google.com>
Cc: Adam Langley <a...@golang.org>, golang-co...@googlegroups.com


Gobot Gobot posted comments on this change.

View Change

Patch set 4:TryBot-Result -1

1 of 7 TryBots failed:
Failed on windows-386-gce:
https://storage.googleapis.com/go-build-log/aaf46821/windows-386-gce_90c2815c.log

Consult https://build.golang.org/ to see whether they are new failures.

To view, visit change 38697. To unsubscribe, visit settings.

Gerrit-Project: crypto
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6957e03b940820ded67753c81164a1cc05f78266
Gerrit-Change-Number: 38697
Gerrit-PatchSet: 4
Gerrit-Owner: Han-Wen Nienhuys <han...@google.com>
Gerrit-Reviewer: Adam Langley <a...@golang.org>
Gerrit-Reviewer: Gobot Gobot <go...@golang.org>
Gerrit-Reviewer: Han-Wen Nienhuys <han...@google.com>
Gerrit-Comment-Date: Thu, 13 Apr 2017 11:51:09 +0000
Gerrit-HasComments: No
Gerrit-HasLabels: Yes


--

Google Germany GmbH, Erika-Mann-Strasse 33, 80363 Munich

Registergericht und -nummer: Hamburg, HRB 86891

Sitz der Gesellschaft: Hamburg

Geschäftsführer: Matthew Scott Sucherman, Paul Terence Manicle

[Russ Cox]

Normally there should be a dump. The fact that there isn't suggests it was super-wedged.

Russ

--
You received this message because you are subscribed to the Google Groups "golang-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to golang-dev+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[brainman]

> On Thursday, 13 April 2017 21:57:04 UTC+10, Han-Wen Nienhuys wrote:

> for some reason, this times out on Windows. Would it be possible to 

> get a goroutine dump of the hang? 

I can reproduce it here:

```

c:\Users\Alex\dev\src\golang.org\x\crypto\ssh>go test -v -run=TestHandshakeBasic -short -timeout=5s

=== RUN   TestHandshakeBasic

panic: test timed out after 5s

goroutine 8 [running]:

testing.startAlarm.func1()

        c:/users/alex/dev/go/src/testing/testing.go:1029 +0x100

created by time.goFunc

        c:/users/alex/dev/go/src/time/sleep.go:170 +0x4b

goroutine 1 [chan receive]:

testing.(*T).Run(0xc042062dd0, 0x7676f2, 0x12, 0x77d5e0, 0x47f201)

        c:/users/alex/dev/go/src/testing/testing.go:702 +0x2fa

testing.runTests.func1(0xc042062dd0)

        c:/users/alex/dev/go/src/testing/testing.go:888 +0x6e

testing.tRunner(0xc042062dd0, 0xc042051e10)

        c:/users/alex/dev/go/src/testing/testing.go:659 +0x9f

testing.runTests(0xc04216e100, 0x92d700, 0x70, 0x70, 0x94eaa0)

        c:/users/alex/dev/go/src/testing/testing.go:886 +0x2bc

testing.(*M).Run(0xc042051f20, 0xc042051f78)

        c:/users/alex/dev/go/src/testing/testing.go:828 +0xfe

main.main()

        golang.org/x/crypto/ssh/_test/_testmain.go:278 +0xe2

goroutine 19 [chan receive]:

golang.org/x/crypto/ssh.(*handshakeTransport).readPacket(...)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:179

golang.org/x/crypto/ssh.TestHandshakeBasic(0xc042062ea0)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake_test.go:184 +0x3a6

testing.tRunner(0xc042062ea0, 0x77d5e0)

        c:/users/alex/dev/go/src/testing/testing.go:659 +0x9f

created by testing.(*T).Run

        c:/users/alex/dev/go/src/testing/testing.go:701 +0x2dc

goroutine 21 [chan receive]:

golang.org/x/crypto/ssh.TestHandshakeBasic.func1(0xc04218e4e0, 0xc042198000, 0xc042062ea0, 0xc04218e540, 0xc042182240)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake_test.go:161 +0x14a

created by golang.org/x/crypto/ssh.TestHandshakeBasic

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake_test.go:149 +0x34b

goroutine 4 [chan receive]:

golang.org/x/crypto/ssh.(*handshakeTransport).readOnePacket(0xc042198000, 0xc042185f00, 0xc04218267e, 0x1, 0x1, 0x0, 0x0)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:403 +0x1ce

golang.org/x/crypto/ssh.(*handshakeTransport).readLoop(0xc042198000)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:189 +0x3f

created by golang.org/x/crypto/ssh.newClientTransport

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:126 +0x18a

goroutine 5 [chan receive]:

golang.org/x/crypto/ssh.(*syncChecker).Check(...)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake_test.go:315

golang.org/x/crypto/ssh.(*syncChecker).Check-fm(0x7632cb, 0x4, 0x8f15e0, 0xc04218c090, 0x8f2e60, 0xc042003120, 0x0, 0x0)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake_test.go:134 +0x81

golang.org/x/crypto/ssh.(*handshakeTransport).client(0xc042198000, 0x8f11e0, 0x94e268, 0xc042194d80, 0xc04202f320, 0x1, 0x0, 0xc042012000)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:633 +0x18f

golang.org/x/crypto/ssh.(*handshakeTransport).enterKeyExchange(0xc042198000, 0xc042190b40, 0x20b, 0x20b, 0x0, 0x0)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:579 +0x647

golang.org/x/crypto/ssh.(*handshakeTransport).kexLoop(0xc042198000)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:295 +0x2b1

created by golang.org/x/crypto/ssh.newClientTransport

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:127 +0x1ac

goroutine 6 [chan receive]:

golang.org/x/crypto/ssh.(*handshakeTransport).readOnePacket(0xc042198160, 0xc0421a1f00, 0xc04218267c, 0x1, 0x1, 0x0, 0x0)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:403 +0x1ce

golang.org/x/crypto/ssh.(*handshakeTransport).readLoop(0xc042198160)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:189 +0x3f

created by golang.org/x/crypto/ssh.newServerTransport

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:134 +0xef

goroutine 7 [IO wait]:

internal/poll.runtime_pollWait(0x2094d80, 0x72, 0x8f0360)

        c:/users/alex/dev/go/src/runtime/netpoll.go:173 +0x60

internal/poll.(*pollDesc).wait(0xc042190158, 0x72, 0x8ed348, 0x0)

        c:/users/alex/dev/go/src/internal/poll/fd_poll_runtime.go:85 +0xb5

internal/poll.(*ioSrv).ExecIO(0x92e300, 0xc042190018, 0x763b25, 0x7, 0x77d9e0, 0x0, 0xc0421900b8, 0x0)

        c:/users/alex/dev/go/src/internal/poll/fd_windows.go:191 +0x10d

internal/poll.(*FD).Read(0xc042190000, 0xc042196000, 0x1000, 0x1000, 0x0, 0x0, 0x0)

        c:/users/alex/dev/go/src/internal/poll/fd_windows.go:418 +0x285

net.(*netFD).Read(0xc042190000, 0xc042196000, 0x1000, 0x1000, 0x48b041, 0xc0421900b8, 0x0)

        c:/users/alex/dev/go/src/net/fd_windows.go:153 +0x59

net.(*conn).Read(0xc042004010, 0xc042196000, 0x1000, 0x1000, 0x0, 0x0, 0x0)

        c:/users/alex/dev/go/src/net/net.go:182 +0x74

bufio.(*Reader).Read(0xc04202e180, 0xc04205d4a1, 0x5, 0x5, 0xc0421900b8, 0xe4dde32526bf9861, 0x6e3ef88f1548bba0)

        c:/users/alex/dev/go/src/bufio/bufio.go:213 +0x320

io.ReadAtLeast(0x8ee820, 0xc04202e180, 0xc04205d4a1, 0x5, 0x5, 0x5, 0xc042027c20, 0x40467a, 0xc04202e298)

        c:/users/alex/dev/go/src/io/io.go:307 +0xa3

io.ReadFull(0x8ee820, 0xc04202e180, 0xc04205d4a1, 0x5, 0x5, 0xc04200c080, 0x20, 0x0)

        c:/users/alex/dev/go/src/io/io.go:325 +0x5f

golang.org/x/crypto/ssh.(*streamPacketCipher).readPacket(0xc04205d480, 0xc000000005, 0x8ee820, 0xc04202e180, 0xc04202e240, 0x1, 0xc04200a240, 0x8eea20, 0xc042032670)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/cipher.go:150 +0x83

golang.org/x/crypto/ssh.(*connectionState).readPacket(0xc04200e240, 0xc04202e180, 0xc042182a58, 0x1, 0x1, 0x0, 0x0)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/transport.go:129 +0x6f

golang.org/x/crypto/ssh.(*transport).readPacket(0xc04200e240, 0xc042182a58, 0x1, 0x1, 0x0, 0x0)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/transport.go:113 +0x3e

golang.org/x/crypto/ssh.(*handshakeTransport).enterKeyExchange(0xc042198160, 0xc042071c00, 0x31d, 0x31d, 0x0, 0x0)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:597 +0x4a4

golang.org/x/crypto/ssh.(*handshakeTransport).kexLoop(0xc042198160)

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:295 +0x2b1

created by golang.org/x/crypto/ssh.newServerTransport

        c:/users/alex/dev/src/golang.org/x/crypto/ssh/handshake.go:135 +0x111

exit status 2

FAIL    golang.org/x/crypto/ssh 5.592s

c:\Users\Alex\dev\src\golang.org\x\crypto\ssh>

```

I hope it is helpful enough.

I did not even look at the code, but if you want me to debug this, just let me know.

> On Friday, 14 April 2017 00:04:58 UTC+10, rsc wrote:

> Normally there should be a dump. The fact that there isn't suggests it was super-wedged.

I wonder why it prints stack trace for me.

Alex