[Twisted-Python] SSHSessionProcessProtocol.inConnectionLost() behavior and Git over Conch

Hi All, I've been struggling with this issue off and on for the better part of a month now. Having implemented a simple git SSH server using some of the Conch examples in the official documentation, I encountered an issue that would cause a git client to throw an error only part of the time. The little program to reproduce the issue is found at http://gist.github.com/321403 (raw version for download) http://gist.github.com/raw/321403/82ab2111a2709c8fe50a77aabb08565749087408/g... and can be executed to start the sample server. Run a command like # The /abspath/to/git/repo should be readable by the server user $ git clone ssh://user@localhost:2222/abspath/to/git/repo (password "user") To test the server. On my workstation, I am able to reproduce the error at least once every 5 tries. It's definitely not consistent. The behavior I see is attached at the end of this email. The client fails due to a premature inConnectionLost() call in the SSHSessionProcessProtocol that sends an EOF. As a workaround, when TraceProcessProtocol.inConnectionLost() is overriden to do nothing, the client error goes away. This is somewhat foreign territory for me so I'm not sure whether it's a bug in git or whether it's a bug in the twisted ProcessProtocol implementation. RFC 4254 isn't terribly helpful here: 5.3. Closing a Channel When a party will no longer send more data to a channel, it SHOULD send SSH_MSG_CHANNEL_EOF. So on the surface the current behavior of sending an EOF appears fine, however, I can't really find any definitive cases of this type of problem popping up via, say, default OpenSSH/git combinations. Any advice? Is the gitconnbug.py implementation flawed? Should I open a ticket? Any git experts know of a case where git-upload-pack might close it's stdout pipe? Thanks, Bo Successful case (server side logging, timestamp cut out): [SSHChannel session (0) on SSHService ssh-connection on SSHServerTransport,1,127.0.0.1] executing command "git-upload-pack '/Users/bshi/sandbox/poop'" [-] TPP.outReceived(...) 199 bytes [-] TPP.outReceived(...) 146 bytes [-] TPP.outReceived(...) 8 bytes [-] TPP.outReceived(...) 33 bytes [-] TPP.outReceived(...) 41 bytes [-] TPP.outReceived(...) 77 bytes [-] TPP.outReceived(...) 1228 bytes [-] TPP.outReceived(...) 8192 bytes [-] TPP.outReceived(...) 4567 bytes [-] TPP.inConnectionLost() [-] sending eof [-] exitCode: 0 Successful case (client-side shell session): $ GIT_TRACE=1 git clone ssh://user@localhost:2222/Users/bshi/sandbox/poop trace: built-in: git 'clone' 'ssh://user@localhost:2222/Users/bshi/sandbox/poop' Initialized empty Git repository in /tmp/poop/.git/ trace: run_command: 'ssh' '-p' '2222' 'user@localhost' 'git-upload-pack '\''/Users/bshi/sandbox/poop'\''' user@localhost's password: trace: run_command: 'index-pack' '--stdin' '-v' '--fix-thin' '--keep=fetch-pack 763 on Bo-Shis-MacBook-Pro.local' trace: exec: 'git' 'index-pack' '--stdin' '-v' '--fix-thin' '--keep=fetch-pack 763 on Bo-Shis-MacBook-Pro.local' trace: exec: 'git-index-pack' '--stdin' '-v' '--fix-thin' '--keep=fetch-pack 763 on Bo-Shis-MacBook-Pro.local' trace: run_command: 'git-index-pack' '--stdin' '-v' '--fix-thin' '--keep=fetch-pack 763 on Bo-Shis-MacBook-Pro.local' remote: Counting objects: 50, done. remote: Compressing objects: 100% (35/35), done. remote: Total 50 (delta 16), reused 43 (delta 14) Receiving objects: 100% (50/50), 12.36 KiB, done. Resolving deltas: 100% (16/16), done. Failure case (server side): [SSHChannel session (0) on SSHService ssh-connection on SSHServerTransport,2,127.0.0.1] executing command "git-upload-pack '/Users/bshi/sandbox/poop'" [-] TPP.outReceived(...) 345 bytes [-] TPP.outReceived(...) 8 bytes [-] TPP.outReceived(...) 33 bytes [-] TPP.outReceived(...) 8192 bytes [-] TPP.inConnectionLost() [-] sending eof [-] TPP.outReceived(...) 5903 bytes [-] exitCode: 0 [-] sending request exit-status [-] sending close 0 Failure case ("trace:" messages similar, cut out for readability): $ GIT_TRACE=1 git clone ssh://user@localhost:2222/Users/bshi/sandbox/poop user@localhost's password: ... ... remote: Counting objects: 50, done. fatal: The remote end hung up unexpectedly fatal: early EOF fatal: index-pack failed

On 4 March 2010 17:46, Bo Shi <bs1984@gmail.com> wrote:
Hi All,
I've been struggling with this issue off and on for the better part of a month now. Having implemented a simple git SSH server using some of the Conch examples in the official documentation, I encountered an issue that would cause a git client to throw an error only part of the time.
I think it's a bug in conch.
The little program to reproduce the issue is found at
(raw version for download) http://gist.github.com/raw/321403/82ab2111a2709c8fe50a77aabb08565749087408/g...
and can be executed to start the sample server. Run a command like
# The /abspath/to/git/repo should be readable by the server user $ git clone ssh://user@localhost:2222/abspath/to/git/repo (password "user")
To test the server. On my workstation, I am able to reproduce the error at least once every 5 tries. It's definitely not consistent. The behavior I see is attached at the end of this email. The client fails due to a premature inConnectionLost() call in the SSHSessionProcessProtocol that sends an EOF.
As a workaround, when TraceProcessProtocol.inConnectionLost() is overriden to do nothing, the client error goes away. This is somewhat foreign territory for me so I'm not sure whether it's a bug in git or whether it's a bug in the twisted ProcessProtocol implementation. RFC 4254 isn't terribly helpful here:
5.3. Closing a Channel
When a party will no longer send more data to a channel, it SHOULD send SSH_MSG_CHANNEL_EOF.
So on the surface the current behavior of sending an EOF appears fine, however, I can't really find any definitive cases of this type of problem popping up via, say, default OpenSSH/git combinations.
Any advice? Is the gitconnbug.py implementation flawed? Should I open a ticket? Any git experts know of a case where git-upload-pack might close it's stdout pipe?
I think what's actually happening here is that git-upload-pack is closing its *stdin*. Why conch reacts to that by shutting down the channel, I don't really know -- it doesn't seem right to me. Maybe it's a simple logic error and it method should be 'outConnectionClosed' instead? At any rate, I think this is a bug -- please file a ticket. And thanks for the complete example! Cheers, mwh

Thanks Michael; I have filed #4350. On Thu, Mar 4, 2010 at 11:51 PM, Michael Hudson-Doyle <micahel@gmail.com> wrote:
On 4 March 2010 17:46, Bo Shi <bs1984@gmail.com> wrote:
Hi All,
I've been struggling with this issue off and on for the better part of a month now. Having implemented a simple git SSH server using some of the Conch examples in the official documentation, I encountered an issue that would cause a git client to throw an error only part of the time.
I think it's a bug in conch.
The little program to reproduce the issue is found at
(raw version for download) http://gist.github.com/raw/321403/82ab2111a2709c8fe50a77aabb08565749087408/g...
and can be executed to start the sample server. Run a command like
# The /abspath/to/git/repo should be readable by the server user $ git clone ssh://user@localhost:2222/abspath/to/git/repo (password "user")
To test the server. On my workstation, I am able to reproduce the error at least once every 5 tries. It's definitely not consistent. The behavior I see is attached at the end of this email. The client fails due to a premature inConnectionLost() call in the SSHSessionProcessProtocol that sends an EOF.
As a workaround, when TraceProcessProtocol.inConnectionLost() is overriden to do nothing, the client error goes away. This is somewhat foreign territory for me so I'm not sure whether it's a bug in git or whether it's a bug in the twisted ProcessProtocol implementation. RFC 4254 isn't terribly helpful here:
5.3. Closing a Channel
When a party will no longer send more data to a channel, it SHOULD send SSH_MSG_CHANNEL_EOF.
So on the surface the current behavior of sending an EOF appears fine, however, I can't really find any definitive cases of this type of problem popping up via, say, default OpenSSH/git combinations.
Any advice? Is the gitconnbug.py implementation flawed? Should I open a ticket? Any git experts know of a case where git-upload-pack might close it's stdout pipe?
I think what's actually happening here is that git-upload-pack is closing its *stdin*. Why conch reacts to that by shutting down the channel, I don't really know -- it doesn't seem right to me. Maybe it's a simple logic error and it method should be 'outConnectionClosed' instead?
At any rate, I think this is a bug -- please file a ticket. And thanks for the complete example!
Cheers, mwh
_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com http://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python
-- Bo Shi 617-942-1744

On Mar 4, 2010, at 11:51 PM, Michael Hudson-Doyle wrote:
Maybe it's a simple logic error and it method should be 'outConnectionClosed' instead?
I'd agree with that. Clearly it should not be sending EOF there for the server process closing its stdin. One more detail though: you actually need to wait for both stdout and stderr to close, not just stdout. [[[Sidenote: There *is* no standard SSH protocol message for closing your stdin. But if openssh 5.1 or later connects to an openssh 5.1 or later server, it will use the nonstandard eow@openssh.org command to indicate a closed stdin. Thus, on standard ssh servers/clients, the command: ssh hostname yes | true will hang forever. True closed its stdin by virtue of exiting, but that can't get propagated across the ssh link. So, yes never gets a SIGPIPE, and thus never closes its stdout and the command keeps running forever. But on openssh 5.1 or greater on both ends, it will "work properly". BTW, you can't reasonably implement this extension in conch even if you wanted to, because openssh client will only send it to servers which identify themselves as openssh servers. http://www.openbsd.org/cgi-bin/cvsweb/src/usr.bin/ssh/PROTOCOL ]]] James

On Mar 5, 2010, at 12:07 PM, James Y Knight wrote:
BTW, you can't reasonably implement this extension in conch even if you wanted to, because openssh client will only send it to servers which identify themselves as openssh servers.
Does it just test the banner for being identical, or could we have Conch identify itself as OpenSSH, version (5.1.something+Conch-Not-OpenSSH)?
participants (4)
-
Bo Shi
-
Glyph Lefkowitz
-
James Y Knight
-
Michael Hudson-Doyle