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

Jump to bottom

x/crypto/ssh: OpenSSH hanging on loading shell prompt on 7.3p1+ #19788

Closed
caod123 opened this issue Mar 30, 2017 · 5 comments
Closed

x/crypto/ssh: OpenSSH hanging on loading shell prompt on 7.3p1+ #19788

caod123 opened this issue Mar 30, 2017 · 5 comments
Labels
FrozenDueToAge
Milestone
Unreleased

Comments

@caod123
Copy link

caod123 commented Mar 30, 2017

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

1.8

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

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/cfdojo/workspace/diego-release"
GORACE=""
GOROOT="/usr/local/Cellar/go/1.8/libexec"
GOTOOLDIR="/usr/local/Cellar/go/1.8/libexec/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/z7/g9fftkv12493psx5nsmpcslm0000gn/T/go-build598478375=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"

What did you do?

Thanks to @keymon for the simple repro steps below in https://github.com/cloudfoundry/diego-ssh/issues/31

# Get the diego release for the dependencies
git clone https://github.com/cloudfoundry/diego-release
cd diego-release
./scripts/update

# Use diego release as GOPATH
export GOPATH=$(pwd)

# Compile sshd 
CGO_ENABLED=0 go build -a -installsuffix static code.cloudfoundry.org/diego-ssh/cmd/sshd

# Run sshd without authentication.
./sshd \
	--allowedKeyExchanges= \
	--address=0.0.0.0:2223 \
	--allowUnauthenticatedClients=true \
	--inheritDaemonEnv=true \
	--allowedCiphers= \
	--allowedMACs= \
	--logLevel=debug \
	--debugAddr=

# In another shell attempt to ssh
ssh -p 2223 -vvv localhost

What did you expect to see?

ssh session successfully loads interactive shell prompt

What did you see instead?

OpenSSH_7.5p1, OpenSSL 1.0.2k  26 Jan 2017
...
debug3: send packet: type 21
debug2: set_newkeys: mode 1
debug1: rekey after 4294967296 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 4294967296 blocks
debug2: key: /Volumes/dannycf/id_rsa (0x7ff6e8900690), agent
debug2: key: keypair/id_rsa_bosh (0x7ff6e89005f0), agent
debug2: key: /Users/cfdojo/.ssh/id_rsa (0x0)
debug2: key: /Users/cfdojo/.ssh/id_dsa (0x0)
debug2: key: /Users/cfdojo/.ssh/id_ecdsa (0x0)
debug2: key: /Users/cfdojo/.ssh/id_ed25519 (0x0)
debug3: send packet: type 5
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 52
debug1: Authentication succeeded (none).
Authenticated to localhost ([127.0.0.1]:2223).
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: callback start
debug2: fd 5 setting TCP_NODELAY
debug3: ssh_packet_set_tos: set IP_TOS 0x10
debug2: client_session2_setup: id 0
debug2: channel 0: request pty-req confirm 1
debug3: send packet: type 98
debug2: channel 0: request shell confirm 1
debug3: send packet: type 98
debug2: callback done
debug2: channel 0: open confirm rwindow 2097152 rmax 32768
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: PTY allocation request accepted on channel 0
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: shell request accepted on channel 0

Hangs here
@gopherbot gopherbot added this to the Unreleased milestone Mar 30, 2017
@caod123
Copy link
Author

caod123 commented Mar 30, 2017 •
edited

Some interesting things to note

  • This works in 7.2 and under, but not 7.3+
  • Non-interactive ssh sessions work as intended
> ssh -p 2223 -vvv localhost 'echo Success'
...
debug3: send packet: type 21
debug2: set_newkeys: mode 1
debug1: rekey after 4294967296 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 4294967296 blocks
debug2: key: /Volumes/dannycf/id_rsa (0x7fb52c200e90), agent
debug2: key: keypair/id_rsa_bosh (0x7fb52ac0c970), agent
debug2: key: /Users/cfdojo/.ssh/id_rsa (0x0)
debug2: key: /Users/cfdojo/.ssh/id_dsa (0x0)
debug2: key: /Users/cfdojo/.ssh/id_ecdsa (0x0)
debug2: key: /Users/cfdojo/.ssh/id_ed25519 (0x0)
debug3: send packet: type 5
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 52
debug1: Authentication succeeded (none).
Authenticated to localhost ([127.0.0.1]:2223).
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: callback start
debug2: fd 5 setting TCP_NODELAY
debug3: ssh_packet_set_tos: set IP_TOS 0x08
debug2: client_session2_setup: id 0
debug1: Sending command: echo Success
debug2: channel 0: request exec confirm 1
debug3: send packet: type 98
debug2: callback done
debug2: channel 0: open confirm rwindow 2097152 rmax 32768
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: exec request accepted on channel 0
Success
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug2: channel 0: output open -> drain
debug2: channel 0: close_read
debug2: channel 0: input open -> closed
debug3: channel 0: will not send data after close
debug2: channel 0: obuf empty
debug2: channel 0: close_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 r0 i3/0 o3/0 fd -1/-1 cc -1)

debug3: send packet: type 1
Transferred: sent 1744, received 1084 bytes, in 0.0 seconds
Bytes per second: sent 212555.0, received 132115.6
debug1: Exit status 0

@hanwen
Copy link
Contributor

hanwen commented Mar 30, 2017

I won't have time to look at this this week. Some questions:

  • what does a stacktrace from Go look like?

  • is there a recent commit to crypto/ssh that introduced this?

@caod123
Copy link
Author

caod123 commented Mar 30, 2017 

SIGABRT: abort
PC=0x1059dab m=0 sigcode=0

goroutine 0 [idle]:
runtime.mach_semaphore_wait(0x903, 0x0, 0x0, 0x0, 0x0, 0x190b580, 0x7fff5fbfe830, 0x1054213, 0xffffffffffffffff, 0x0, ...)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/sys_darwin_amd64.s:415 +0xb
runtime.semasleep1(0xffffffffffffffff, 0x0)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/os_darwin.go:413 +0x4b
runtime.semasleep.func1()
        /usr/local/Cellar/go/1.8/libexec/src/runtime/os_darwin.go:432 +0x33
runtime.systemstack(0x7fff5fbfe858)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/asm_amd64.s:343 +0xab
runtime.semasleep(0xffffffffffffffff, 0x0)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/os_darwin.go:433 +0x4d
runtime.notesleep(0x190bc10)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/lock_sema.go:166 +0xb2
runtime.stopm()
        /usr/local/Cellar/go/1.8/libexec/src/runtime/proc.go:1650 +0xad
runtime.findrunnable(0xc420025300, 0x0)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/proc.go:2102 +0x2e4
runtime.schedule()
        /usr/local/Cellar/go/1.8/libexec/src/runtime/proc.go:2222 +0x14c
runtime.park_m(0xc4200649c0)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/proc.go:2285 +0xab
runtime.mcall(0x7fff5fbfea30)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/asm_amd64.s:269 +0x5b

goroutine 1 [chan receive]:
main.main()
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/cmd/sshd/main.go:156 +0x6bd

goroutine 18 [syscall]:
os/signal.signal_recv(0x0)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/sigqueue.go:116 +0xff
os/signal.loop()
        /usr/local/Cellar/go/1.8/libexec/src/os/signal/signal_unix.go:22 +0x22
created by os/signal.init.1
        /usr/local/Cellar/go/1.8/libexec/src/os/signal/signal_unix.go:28 +0x41

goroutine 33 [chan receive]:
github.com/tedsuo/ifrit.(*process).Wait.func1(0xc420018980, 0xc4201c0060)
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:83 +0x44
created by github.com/tedsuo/ifrit.(*process).Wait
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:85 +0x67

goroutine 4 [select]:
github.com/tedsuo/ifrit/sigmon.sigmon.Run(0xc42000b7a0, 0x2, 0x2, 0x18c15c0, 0xc420017950, 0xc420020840, 0xc4200208a0, 0x0, 0x0)
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/sigmon/sigmon.go:35 +0x317
github.com/tedsuo/ifrit/sigmon.(*sigmon).Run(0xc420017980, 0xc420020840, 0xc4200208a0, 0x0, 0x0)
        <autogenerated>:1 +0x7d
github.com/tedsuo/ifrit.(*process).run(0xc420018980)
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:71 +0x49
created by github.com/tedsuo/ifrit.Background
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:49 +0x12f

goroutine 5 [chan receive]:
github.com/tedsuo/ifrit.(*process).Wait.func1(0xc420018980, 0xc420020960)
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:83 +0x44
created by github.com/tedsuo/ifrit.(*process).Wait
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:85 +0x67

goroutine 20 [select, locked to thread]:
runtime.gopark(0x1657b10, 0x0, 0x1630c4d, 0x6, 0x18, 0x2)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/proc.go:271 +0x13a
runtime.selectgoImpl(0xc4201acf50, 0x0, 0x18)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/select.go:423 +0x1364
runtime.selectgo(0xc4201acf50)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/select.go:238 +0x1c
runtime.ensureSigM.func1()
        /usr/local/Cellar/go/1.8/libexec/src/runtime/signal_unix.go:434 +0x265
runtime.goexit()
        /usr/local/Cellar/go/1.8/libexec/src/runtime/asm_amd64.s:2197 +0x1

goroutine 21 [select]:
reflect.rselect(0xc420082f40, 0x2, 0x2, 0xc4200a4ba0, 0x2)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/select.go:711 +0xee
reflect.Select(0xc420150930, 0x2, 0x2, 0xc4200a4ba0, 0x12, 0x2, 0x4, 0x18c0f00)
        /usr/local/Cellar/go/1.8/libexec/src/reflect/value.go:2016 +0x972
github.com/tedsuo/ifrit/grouper.(*orderedGroup).waitForSignal(0xc420017950, 0xc4200a4ba0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x18c15c0, 0xc420017950, 0xc420020840)
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/grouper/ordered.go:121 +0x38e
github.com/tedsuo/ifrit/grouper.(*orderedGroup).Run(0xc420017950, 0xc4200a4ba0, 0xc4200a4c00, 0x0, 0x0)
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/grouper/ordered.go:47 +0x135
github.com/tedsuo/ifrit.(*process).run(0xc420082e00)
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:71 +0x49
created by github.com/tedsuo/ifrit.Background
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:49 +0x12f

goroutine 22 [chan receive]:
github.com/tedsuo/ifrit.(*process).Wait.func1(0xc420082e00, 0xc4200a4cc0)
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:83 +0x44
created by github.com/tedsuo/ifrit.(*process).Wait
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:85 +0x67

goroutine 23 [chan receive]:
code.cloudfoundry.org/diego-ssh/server.(*Server).Run(0xc420059ea0, 0xc4200a4d20, 0xc4200a4d80, 0x0, 0x0)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/server/server.go:61 +0xde
github.com/tedsuo/ifrit/grouper.(*Member).Run(0xc4200f5680, 0xc4200a4d20, 0xc4200a4d80, 0x0, 0x0)
        <autogenerated>:1 +0x5e
github.com/tedsuo/ifrit.(*process).run(0xc420082e40)
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:71 +0x49
created by github.com/tedsuo/ifrit.Background
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:49 +0x12f

goroutine 24 [chan receive]:
github.com/tedsuo/ifrit.(*process).Wait.func1(0xc420082e40, 0xc4200a4e40)
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:83 +0x44
created by github.com/tedsuo/ifrit.(*process).Wait
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:85 +0x67

goroutine 25 [IO wait]:
net.runtime_pollWait(0x1a65f70, 0x72, 0x0)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/netpoll.go:164 +0x59
net.(*pollDesc).wait(0xc420150928, 0x72, 0x0, 0xc42000b880)
        /usr/local/Cellar/go/1.8/libexec/src/net/fd_poll_runtime.go:75 +0x38
net.(*pollDesc).waitRead(0xc420150928, 0xffffffffffffffff, 0x0)
        /usr/local/Cellar/go/1.8/libexec/src/net/fd_poll_runtime.go:80 +0x34
net.(*netFD).accept(0xc4201508c0, 0x0, 0x18c2240, 0xc42000b880)
        /usr/local/Cellar/go/1.8/libexec/src/net/fd_unix.go:430 +0x1e5
net.(*TCPListener).accept(0xc4200880a0, 0xc420032ef8, 0x151a3a9, 0x1055120)
        /usr/local/Cellar/go/1.8/libexec/src/net/tcpsock_posix.go:136 +0x2e
net.(*TCPListener).Accept(0xc4200880a0, 0x1656758, 0xc420059ea0, 0x18ccd20, 0xc42000c078)
        /usr/local/Cellar/go/1.8/libexec/src/net/tcpsock.go:228 +0x49
code.cloudfoundry.org/diego-ssh/server.(*Server).Serve(0xc420059ea0)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/server/server.go:120 +0xda
created by code.cloudfoundry.org/diego-ssh/server.(*Server).Run
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/server/server.go:56 +0xa8

goroutine 26 [chan receive]:
github.com/tedsuo/ifrit.(*process).Wait.func1(0xc420082e40, 0xc4200a4f00)
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:83 +0x44
created by github.com/tedsuo/ifrit.(*process).Wait
        /Users/cfdojo/workspace/diego-release/src/github.com/tedsuo/ifrit/process.go:85 +0x67

goroutine 6 [semacquire]:
sync.runtime_notifyListWait(0xc420094210, 0xc400000000)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/sema.go:297 +0x10b
sync.(*Cond).Wait(0xc420094200)
        /usr/local/Cellar/go/1.8/libexec/src/sync/cond.go:57 +0x89
golang.org/x/crypto/ssh.(*mux).Wait(0xc4201ba0e0, 0x0, 0x0)
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/mux.go:110 +0x9c
code.cloudfoundry.org/diego-ssh/daemon.(*Daemon).HandleConnection(0xc4200178c0, 0x18ccd20, 0xc42000c078)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/daemon/daemon.go:48 +0x284
code.cloudfoundry.org/diego-ssh/server.(*Server).Serve.func1(0xc420059ea0, 0x18ccd20, 0xc42000c078)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/server/server.go:142 +0x4c
created by code.cloudfoundry.org/diego-ssh/server.(*Server).Serve
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/server/server.go:148 +0x369

goroutine 7 [IO wait]:
net.runtime_pollWait(0x1a65eb0, 0x72, 0x5)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/netpoll.go:164 +0x59
net.(*pollDesc).wait(0xc420059f78, 0x72, 0x18c3c40, 0x18bf3f8)
        /usr/local/Cellar/go/1.8/libexec/src/net/fd_poll_runtime.go:75 +0x38
net.(*pollDesc).waitRead(0xc420059f78, 0xc4201e4000, 0x1000)
        /usr/local/Cellar/go/1.8/libexec/src/net/fd_poll_runtime.go:80 +0x34
net.(*netFD).Read(0xc420059f10, 0xc4201e4000, 0x1000, 0x1000, 0x0, 0x18c3c40, 0x18bf3f8)
        /usr/local/Cellar/go/1.8/libexec/src/net/fd_unix.go:250 +0x1b7
net.(*conn).Read(0xc42000c078, 0xc4201e4000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
        /usr/local/Cellar/go/1.8/libexec/src/net/net.go:181 +0x70
bufio.(*Reader).Read(0xc420020b40, 0xc420166ea1, 0x5, 0x5, 0x0, 0x0, 0x3000000000000)
        /usr/local/Cellar/go/1.8/libexec/src/bufio/bufio.go:213 +0x312
io.ReadAtLeast(0x18c0b40, 0xc420020b40, 0xc420166ea1, 0x5, 0x5, 0x5, 0x20, 0x20, 0x100000000000020)
        /usr/local/Cellar/go/1.8/libexec/src/io/io.go:307 +0xa9
io.ReadFull(0x18c0b40, 0xc420020b40, 0xc420166ea1, 0x5, 0x5, 0x0, 0x1, 0x0)
        /usr/local/Cellar/go/1.8/libexec/src/io/io.go:325 +0x58
golang.org/x/crypto/ssh.(*streamPacketCipher).readPacket(0xc420166e80, 0xc400000008, 0x18c0b40, 0xc420020b40, 0xf, 0xf, 0x15f, 0x0, 0x0)
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/cipher.go:150 +0x7c
golang.org/x/crypto/ssh.(*connectionState).readPacket(0xc4201e6000, 0xc420020b40, 0xc4201aefb0, 0xf, 0xf, 0x0, 0x0)
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/transport.go:129 +0x68
golang.org/x/crypto/ssh.(*transport).readPacket(0xc4201e6000, 0xc420096550, 0xf, 0xf, 0xc420020cb8, 0x0)
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/transport.go:113 +0x37
golang.org/x/crypto/ssh.(*handshakeTransport).readOnePacket(0xc420174580, 0xc420020c00, 0xc4201aefb0, 0xf, 0xf, 0x0, 0x0)
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/handshake.go:348 +0x48
golang.org/x/crypto/ssh.(*handshakeTransport).readLoop(0xc420174580)
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/handshake.go:189 +0x38
created by golang.org/x/crypto/ssh.newServerTransport
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/handshake.go:134 +0x21f

goroutine 8 [select]:
golang.org/x/crypto/ssh.(*handshakeTransport).kexLoop(0xc420174580)
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/handshake.go:249 +0x813
created by golang.org/x/crypto/ssh.newServerTransport
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/handshake.go:135 +0x241

goroutine 34 [chan receive]:
golang.org/x/crypto/ssh.(*handshakeTransport).readPacket(0xc420174580, 0xc420096550, 0xf, 0xf, 0x0, 0x0)
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/handshake.go:179 +0x64
golang.org/x/crypto/ssh.(*mux).onePacket(0xc4201ba0e0, 0x0, 0x0)
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/mux.go:215 +0x37
golang.org/x/crypto/ssh.(*mux).loop(0xc4201ba0e0)
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/mux.go:190 +0x43
created by golang.org/x/crypto/ssh.newMux
        /Users/cfdojo/workspace/diego-release/src/golang.org/x/crypto/ssh/mux.go:128 +0x1a3

goroutine 35 [chan receive]:
code.cloudfoundry.org/diego-ssh/daemon.(*Daemon).handleGlobalRequests(0xc4200178c0, 0x18ccc00, 0xc420021bc0, 0xc4201c0180)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/daemon/daemon.go:56 +0x161
created by code.cloudfoundry.org/diego-ssh/daemon.(*Daemon).HandleConnection
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/daemon/daemon.go:45 +0x22e

goroutine 36 [chan receive]:
code.cloudfoundry.org/diego-ssh/daemon.(*Daemon).handleNewChannels(0xc4200178c0, 0x18ccc00, 0xc4201c01e0, 0xc4201c00c0)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/daemon/daemon.go:79 +0x173
created by code.cloudfoundry.org/diego-ssh/daemon.(*Daemon).HandleConnection
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/daemon/daemon.go:46 +0x26e

goroutine 37 [semacquire]:
sync.runtime_SemacquireMutex(0xc4201b241c)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/sema.go:62 +0x34
sync.(*Mutex).Lock(0xc4201b2418)
        /usr/local/Cellar/go/1.8/libexec/src/sync/mutex.go:87 +0x9d
code.cloudfoundry.org/diego-ssh/handlers.(*session).destroy(0xc4201b23c0)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/handlers/session_channel_handler.go:618 +0x12a
panic(0x159af40, 0x18faa40)
        /usr/local/Cellar/go/1.8/libexec/src/runtime/panic.go:489 +0x2cf
code.cloudfoundry.org/diego-ssh/handlers.setTerminalAttributes(0x18ccc00, 0xc4201c07e0, 0xc42008e0f0, 0xc4201f4200, 0x100)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/handlers/session_channel_handler.go:518 +0x5a1
code.cloudfoundry.org/diego-ssh/handlers.(*session).runWithPty(0xc4201b23c0, 0xc4201be2c0, 0x0, 0x0)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/handlers/session_channel_handler.go:566 +0x20e
code.cloudfoundry.org/diego-ssh/handlers.(*session).executeShell(0xc4201b23c0, 0xc420094680, 0x0, 0x0, 0x0)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/handlers/session_channel_handler.go:359 +0x132
code.cloudfoundry.org/diego-ssh/handlers.(*session).handleShellRequest(0xc4201b23c0, 0xc420094680)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/handlers/session_channel_handler.go:286 +0x50
code.cloudfoundry.org/diego-ssh/handlers.(*session).serviceRequests(0xc4201b23c0, 0xc4201c03c0)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/handlers/session_channel_handler.go:123 +0x3b3
code.cloudfoundry.org/diego-ssh/handlers.(*SessionChannelHandler).HandleNewChannel(0xc420017860, 0x18ccc00, 0xc4201c01e0, 0x18ca900, 0xc4201b2240)
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/handlers/session_channel_handler.go:58 +0xfd
created by code.cloudfoundry.org/diego-ssh/daemon.(*Daemon).handleNewChannels
        /Users/cfdojo/workspace/diego-release/src/code.cloudfoundry.org/diego-ssh/daemon/daemon.go:86 +0x48a

rax    0xe
rbx    0x190bb00
rcx    0x7fff5fbfe7d0
rdx    0x7fff5fbfe858
rdi    0x903
rsi    0x1
rbp    0x7fff5fbfe808
rsp    0x7fff5fbfe7d0
r8     0x7fff5fbfe848
r9     0x7fff5fbfe0b0
r10    0x0
r11    0x286
r12    0x0
r13    0xa
r14    0x0
r15    0xfc
rip    0x1059dab
rflags 0x286
cs     0x7
fs     0x0
gs     0x0

We didn't notice a particular commit that introduced this. We were however noticing this behavior in https://github.com/cloudfoundry/diego-ssh/issues/30 which at the time was using golang/crypto@d68c3e (a fairly old commit). Upon updating crypto to master we were still seeing this behavior.

@caod123
Copy link
Author

caod123 commented Mar 30, 2017

Actually it turns out the issue was on our end. OpenSSH 7.3+ introduces a new opcode specified here that we didn't correctly process in our ssh server. Credit to @ematpl and @jvshahid for digging through the stacktrace and finding that. Closing this issue out.

@caod123 caod123 closed this as completed Mar 30, 2017
@emalm
Copy link

emalm commented Mar 30, 2017

Thanks, @caod123 ! For some reason that link is 404ing, but here's an up-to-date link to a later draft: https://tools.ietf.org/html/draft-sgtatham-secsh-iutf8-06.

@golang golang locked and limited conversation to collaborators Mar 30, 2018
@rsc rsc unassigned hanwen Jun 23, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge
Projects
None yet
Milestone
Unreleased
Development

No branches or pull requests
4 participants
@hanwen @caod123 @emalm @gopherbot