[Twisted-Python] conch server can't git clone

[Mark Williams]

On Sun, Nov 5, 2017, at 08:48 PM, Glyph wrote:
> I tried to `git clone` a repository on said server, and I saw these logs on the server:
>
>> 2017-11-06T04:45:49+0000 [SSHChannel session (0) on SSHService 'ssh-connection' on SSHServerTransport,817,1.2.3.4] channel open
>> 2017-11-06T04:45:49+0000 [SSHChannel session (0) on SSHService 'ssh-connection' on SSHServerTransport,817,1.2.3.4] unhandled request for env
>> 2017-11-06T04:45:49+0000 [SSHChannel session (0) on SSHService 'ssh-connection' on SSHServerTransport,817,1.2.3.4] executing command "git-upload-pack '/site'"
>> 2017-11-06T04:45:51+0000 [-] sending eof
>> 2017-11-06T04:45:51+0000 [-] exitCode: 0
>> 2017-11-06T04:45:51+0000 [-] sending request 'exit-status'
>> 2017-11-06T04:45:51+0000 [SSHChannel session (0) on SSHService 'ssh-connection' on SSHServerTransport,817,1.2.3.4] sending close 0
>> 2017-11-06T04:45:51+0000 [SSHChannel session (0) on SSHService 'ssh-connection' on SSHServerTransport,817,1.2.3.4] remote close
>> 2017-11-06T04:45:51+0000 [SSHChannel session (0) on SSHService 'ssh-connection' on SSHServerTransport,817,1.2.3.4] shell closed
>> 2017-11-06T04:45:51+0000 [SSHServerTransport,817,1.2.3.4] Got remote error, code 11
>> reason: disconnected by user
>> 2017-11-06T04:45:51+0000 [SSHServerTransport,817,1.2.3.4] avatar user logging out (0)
>> 2017-11-06T04:45:51+0000 [SSHServerTransport,817,1.2.3.4] connection lost

This looks normal.  I see the same output from a Conch server against
which all git clone calls succeed.

Unfortunately, normal is confusing, so I'll explain my reading of your
log.  The most important part of this is that the 'sending eof' just
means the 'git-upload-pack' process closed stdout and err.  In other
words, I think 'git-upload-pack' is the problem.

The server creates an SSHChanel ("channel open"), then complains that it
cannot answer the client's request for environment variables
(https://tools.ietf.org/html/rfc4254.html#section-6.4) because Conch
doesn't implement that channel request type.  
Conch should probably support it:
https://twistedmatrix.com/trac/ticket/9315

The 'git-upload-pack' command appears to execute successfully: its exit
status is 0 and  SSHSessionProcessProtocol send that back to the client,
per
https://github.com/twisted/twisted/blob/twisted-17.9.0/src/twisted/conch/ssh/session.py#L276-L279

The "sending eof" message you identified as a smoking gun occurs because
'git-upload-pack' closed both stdout and stderr:
https://github.com/twisted/twisted/blob/twisted-17.9.0/src/twisted/conch/ssh/session.py#L220-L221

The server's claim that a 'remote error' occurred is misleading; Conch
calls the SSH transport's receiveError method for all DISCONNECT
messages:

https://github.com/twisted/twisted/blob/twisted-17.9.0/src/twisted/conch/ssh/transport.py#L909-L924

including 11, SSH_DISCONNECT_BY_APPLICATION, which means that the
application willingly terminated the connection:

https://tools.ietf.org/html/rfc4253.html#section-11.1 

OpenSSH's own logging does not consider SSH_DISCONNECT_BY_APPLICATION to
be an error:

https://github.com/openssh/openssh-portable/blob/V_7_6_P1/packet.c#L1703-L1708

Maybe Conch should also filter this:
https://twistedmatrix.com/trac/ticket/9316

> Anyone have any idea how I could debug this?  

You can export the GIT_TRACE_PACKET environment variable on the client
side, which makes git emit packet-level logs:

https://git-scm.com/book/gr/v2/Git-Internals-Environment-Variables

Maybe that will help us figure out why git-pack-upload is terminating
early.

--
  Mark Williams
  mrw at enotuniq.org