openssh bugs - Sep 2010 - [Bug 1818] New: SSH2_MSG_CHANNEL_FAILURE on closed channel

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

           Summary: SSH2_MSG_CHANNEL_FAILURE on closed channel
           Product: Portable OpenSSH
           Version: 5.1p1
          Platform: All
        OS/Version: All
            Status: NEW
          Severity: normal
          Priority: P2
         Component: sshd
        AssignedTo: unassigned-bugs at mindrot.org
        ReportedBy: anakin at pobox.com


When I connect to an OpenSSH server using PuTTY with X11 forwarding,
and run a makefile I use which invokes a large number of X applications
in rapid succession, I find PuTTY terminates the session with a message
along the lines of "Disconnected: Received SSH2_MSG_CHANNEL_FAILURE for
nonexistent channel 257" (the channel number may vary).

I told PuTTY to produce a full session log, which I attach here. (Sorry
it's a bit large.) You can indeed see that PuTTY receives the final
SSH2_MSG_CHANNEL_FAILURE at a point when it has both sent and received
SSH2_MSG_CHANNEL_CLOSE on that channel. RFC 4254 section 5.3 states
that when a party has both sent and received SSH2_MSG_CHANNEL_CLOSE for
a channel, that channel is considered closed for that party and it may
reuse the channel number; PuTTY's indignation at receiving the
CHANNEL_FAILURE at that time therefore seems reasonable to me.

I think what must have happened is that OpenSSHD sent its CHANNEL_CLOSE
before it received the CHANNEL_REQUEST and CHANNEL_CLOSE from PuTTY; so
when _it_ received the CHANNEL_REQUEST, it had sent but not received
CHANNEL_CLOSE, and hence it did not yet consider the channel closed and
felt free to respond to the request.

However, although that sounds reasonable, I think it is in fact wrong
behaviour. I think a direct logical consequence of section 5.3 is that
after sending CHANNEL_CLOSE on a channel a party MUST NOT send any
subsequent responses to channel events - because it can't be sure the
other party hasn't just sent its own CHANNEL_CLOSE, causing exactly
this circumstance. Conversely, on receiving CHANNEL_CLOSE, a party must
discard any outstanding channel requests for which it was expecting to
receive responses, and assume those requests were not received by the
server until after it sent its close. I can't think of any other
interpretation of RFC 4254 devoid of race conditions.

(The channel request type is "winadj at putty.projects.tartarus.org":
a
phony channel request designed to elicit a CHANNEL_FAILURE which PuTTY
uses to tune its window adjustment policy. I don't think that detail is
important except inasmuch as it has the want_reply flag set.)

I report this bug against 5.1p1, because that's the version in Debian
stable. However, I have reproduced the same behaviour with
openssh-SNAP-20100914 downloaded by following the links from
http://www.openssh.com/portable.html, so I don't think this is an
already-fixed issue.

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

--- Comment #1 from Simon Tatham <anakin at pobox.com> 2010-09-14 04:08:37
EST ---
Created attachment 1925
  --> https://bugzilla.mindrot.org/attachment.cgi?id=1925
putty.log : SSH packet log of failing connection (redacted)

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

--- Comment #2 from Simon Tatham <anakin at pobox.com> 2010-09-14 04:10:07
EST ---
Sorry about that; my packet log was apparently too big for Bugzilla to
accept. I've attached a redacted version, produced using the Perl
one-liner

perl -ne 'if (/^\S/) { splice @lines, 2, $#lines-3, "  ...\n" if
$#lines >= 5; print @lines; @lines = (); print; } else { push @lines,
$_; }'

and hopefully that still shows the sequence of events (from PuTTY's
viewpoint) and all important numbers and details without the huge
wodges of irrelevant channel data.

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

--- Comment #3 from Simon Tatham <anakin at pobox.com> 2010-09-14 04:13:15
EST ---
Created attachment 1926
  --> https://bugzilla.mindrot.org/attachment.cgi?id=1926
openssh-channel-failure.diff : proposed patch

Here's a trivial patch which seems to work for me: after I apply this
(against last month's snapshot, not 5.1p1) my complex makefile runs to
completion without any issues at the SSH level. As I discussed in my
comments earlier, it simply suppresses generation of
SSH2_MSG_CHANNEL_{SUCCESS,FAILURE} for channels on which
SSH2_MSG_CHANNEL_CLOSE has already been sent. (It lacks comments and
rationale, though; it's merely a proof of concept.)

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

Simon Tatham <anakin at pobox.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |anakin at pobox.com

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |djm at mindrot.org

--- Comment #4 from Damien Miller <djm at mindrot.org> 2010-09-14 10:51:45
EST ---
Thanks for the detailed report.

I don't see anything in RFC 4254 section 5.3 indicating that a channel
shouldn't send notifications while it is half-closed. Could you explain
how you arrived at this interpretation?

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

--- Comment #5 from Simon Tatham <anakin at pobox.com> 2010-09-14 17:37:42
EST ---
Because if you send anything that arrives at the other side when _it_
thinks the channel is fully closed, that's definitely in violation of
5.3. So if you send stuff after you've sent CLOSE, then it _might_
cross in transit with the other side's CLOSE, in which case it would
arrive at the other side when that side had already both sent and
received CLOSE.

I discussed this last night with a friend, and he pointed out that
there is an alternative protocol fix which also works, but it's more
clearly contradictory of explicit text in the RFC. Instead of ruling
that requests received after we send CLOSE may not be responded to, we
could instead rule that all requests are responded to and modify
section 5.3 to state that a channel number may be reused after you have
both sent and received CLOSE _and_ received replies to all outstanding
channel requests.

However, it's clear that the current situation leads to a problem, so
_something_ needs fixing one way or the other. If you don't agree with
my analysis, should we take this to ietf-secsh and see if we can get a
consensus?

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Blocks|                            |1803

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Blocks|1803                        |

--- Comment #6 from Damien Miller <djm at mindrot.org> 2011-01-24 12:30:44
EST ---
Retarget unclosed bugs from 5.7=>5.8

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Blocks|                            |1845

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Blocks|                            |1930

--- Comment #7 from Damien Miller <djm at mindrot.org> 2011-09-06 10:34:08
EST ---
Retarget unresolved bugs/features to 6.0 release

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

--- Comment #8 from Damien Miller <djm at mindrot.org> 2011-09-06 10:36:23
EST ---
Retarget unresolved bugs/features to 6.0 release

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Blocks|1845                        |

--- Comment #9 from Damien Miller <djm at mindrot.org> 2011-09-06 10:38:56
EST ---
Retarget unresolved bugs/features to 6.0 release

(try again - bugzilla's "change several" isn't)

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Blocks|                            |1986

--- Comment #10 from Damien Miller <djm at mindrot.org> 2012-02-24
10:34:16 EST ---
Retarget from 6.0 to 6.1

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Blocks|1930                        |

--- Comment #11 from Damien Miller <djm at mindrot.org> 2012-02-24
10:37:54 EST ---
Retarget 6.0 => 6.1

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=1818

--- Comment #12 from Simon Tatham <anakin at pobox.com> 2012-02-24
20:13:11 EST ---
I've now worked around this issue on the PuTTY side (at least on the
current development trunk), by implementing a more robust handling of
SSH2_MSG_CHANNEL_CLOSE: _we_ now do not send CHANNEL_CLOSE until we
have seen replies to all our outstanding channel requests, and
therefore the question of which order the server's close and the
request replies appear in is moot.

-- 
Configure bugmail: https://bugzilla.mindrot.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.