x/crypto/ssh: Unable to start subsystem without an exec or shell message

[magisterquis]

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

$ go version
go version go1.13.3 openbsd/amd64

Does this issue reproduce with the latest release?

It does.

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

go env Output

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/stuart/.cache/go-build"
GOENV="/home/stuart/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="openbsd"
GONOPROXY=""
GONOSUMDB=""
GOOS="openbsd"
GOPATH="/home/stuart/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/stuart/.go/1.13.3"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/stuart/.go/1.13.3/pkg/tool/openbsd_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="0"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -fmessage-length=0"

What did you do?

Wrote a little server which implemented an SSH subsystem and tried to write a client to use that subsystem.
A minimal server: http://play.golang.org/p/HtAmPnyMpDl
A minimal client: http://play.golang.org/p/VqSuWARBHJT

What did you expect to see?

Output from the subsystem

What did you see instead?

That the session hadn't been started.

When starting a subsystem, a channel is opened and a subsystem request is sent with the name of the subsystem. According to RFC4254 exactly one of shell, exec, or subsystem requests can succeed per channel, though it doesn't say that only one may be sent. Currently, the subsystem request is sent with session.RequestSubsystem, but there is no way to call the non-exported session.start without calling session.Start (which sends an exec request) or session.Shell (which sends a shell request). This means that to start subsystem, the server will first receive a subsystem request and then an exec or shell request. Changing session.RequestSubsystem to call session.start (i.e. to parallel session.Shell and session.Start) causes the server to start the subsystem and delivers output to the client.

The OpenSSH client only sends a subsystem message. The OpenSSH server replies with false exec request following a subsystem request.

[dmitshur]

/cc @hanwen @FiloSottile per owners.

[skinowski]

Due to this bug, we cannot obtain exit status or signal from subsystem as well. This is because we cannot Session.Wait() on the subsystem. Probably the fix is easy, add the forgotten call to Session.start() in session:

--- a/vendor/golang.org/x/crypto/ssh/session.go
+++ b/vendor/golang.org/x/crypto/ssh/session.go
@@ -221,6 +221,9 @@ type subsystemRequestMsg struct {
 // RequestSubsystem requests the association of a subsystem with the session on the remote host.
 // A subsystem is a predefined command that runs in the background when the ssh session is initiated
 func (s *Session) RequestSubsystem(subsystem string) error {
+       if s.started {
+               return errors.New("ssh: session already started")
+       }
        msg := subsystemRequestMsg{
                Subsystem: subsystem,
        }
@@ -228,7 +231,10 @@ func (s *Session) RequestSubsystem(subsystem string) error {
        if err == nil && !ok {
                err = errors.New("ssh: subsystem request failed")
        }
-       return err
+       if err != nil {
+               return err
+       }
+       return s.start()
 }

[achal1012]

Hi @dmitshur @hanwen @FiloSottile: Did you get a chance to review @skinowski's change above? Appreciate your time!

[hanwen]

The code in session.go has been unchanged since ~2012, so I wasn't too familiar, but I read your report carefully. I think the analysis is correct, but given that nobody has complained about it in 10 years, I suppose OpenSSH actually accepts the [RequestSubsystem("test"), Start("shell")] sequence? Or has this been broken (ie. unused) all this time?

There is no test for this functionality against OpenSSH. We should add one (I think scp is served through a subsystem; we don't need build a full scp client, just check that we can start the subsystem) before we go any further to make sure we understand the status quo and be sure we fix the problem.

[achal1012]

Thank you @hanwen for the quick response: I did a test where I took Server code from @magisterquis A minimal server: http://play.golang.org/p/HtAmPnyMpDl and used OpenSSH client on my Mac to run the scp command using:

scp -P 2222 file.md localhost: and on the server side I got just one request with Type subsystem and sftp name

So looks like the OpenSSH client handles the starting of the same session as the Subsytem session correctly? i.e. no Start is called before calling RequestSubsystem

[hanwen]

I was asking

I suppose OpenSSH actually accepts the [RequestSubsystem("test"), Start("shell")] sequence? Or has this been broken (ie. unused) all this time?

I did a test where I took Server code ..

the way to test this is run a x/crypto/ssh client against OpenSSH server, not the reverse.

[kobrineli]

@magisterquis @achal1012 @hanwen
Hi! Faced with the same problem. It seems like there really must be a private start call inside RequestSubsystem.
Calling Start("shell") after RequestSubsystem doesn't work, because according to RFC 4254 requesting another request from exec, shell and subsystem, must fail.

[puellanivis]

OK, so I’ve randomly come across this while trying to diagnose SFTP issues in pkg/sftp. Particularly, because we’re seeing random unknown io.EOFs coming to clients. So, I figured, hey, I could use Session.Wait to get the status of the sftp subsystem to at least get some start of information about what’s going on, like if there is an exit status error being returned.

So, I pulled up the openssh-portable source code, and the sftp subsystem command does indeed do_exec and start up the process, but on our side, we don’t actually perform the s.start(), which means we cannot call Session.Wait(), even though the remote process has started.

Weirdly, we never noticed this bug in pkg/sftp despite the SubsystemRequest never marking the session as started = true, because we have been calling the Session.StdinPipe and Session.StdoutPipe functions (and this even after the process started!) and this only works because Session.started isn’t set in RequestSubsystem, but also because the StdinPipe and StdoutPipe return the direct underlying channel as io.Writer and io.Reader, so we managed to skirted around ever needing to call Session.start so long as we never needed to call the Session.Wait.

That we’re also not attaching to StderrPipe potentially also has been causing nearly silent flaky issues, but I haven’t looked into how far that rabbit hole goes, because we should be attaching to it anyways. But that we don’t even have a io.Copy(io.Discard, s.ch.Stderr()) going on, there’s got to be some sort of subtle issue going on there.

But this is definitely a bug in this code, and the bug manifests as us being unable to use Session.Wait to get any exit status returned by the subsystem at exit, which—as noted above—is absolutely getting started by the ssh server, and as a hanging Stderr that isn’t even getting discarded. And it’s going to make any further debugging of pkg/sftp#424 basically impossible. (We’ll go ahead and grab to Stderr at least. But getting the exit status of the sftp subsystem is going to be a vital addition to our code to diagnose issues as well.)