[Bug 179] New: sshd sends channel data after sending EOF

[bugzilla-daemon at mindrot.org]

http://bugzilla.mindrot.org/show_bug.cgi?id=179

           Summary: sshd sends channel data after sending EOF
           Product: Portable OpenSSH
           Version: 3.1p1
          Platform: ix86
               URL: http://www.denisbider.com
        OS/Version: Linux
            Status: NEW
          Severity: major
          Priority: P2
         Component: sshd
        AssignedTo: openssh-unix-dev at mindrot.org
        ReportedBy: bugzilla-mindrot-org at denisbider.com


I think this problem has 'major' severity because it causes sshd to violate the 
SSH2 protocol specification in such a way that the connection will immediately 
be terminated by most clients.

There appears to be a semi-deterministic bug in sshd 3.1p1 (tested on SuSE 
Linux) which in certain conditions usually causes sshd to send data on a 
channel after it has already sent EOF, but before it has sent a channel close 
packet. The bug has been observed as follows:

(1) client connects and authenticates
(2) client sends exec request for a program that does not exist
(3) client sends EOF
(4) server sends EOF
(5) server sends extended data after EOF has already been sent

An sshd debug log from one such attempt is as follows:

Server listening on 0.0.0.0 port 22.
debug1: Server will not fork when running in debugging mode.
Connection from 10.1.1.2 port 2283
debug1: Client protocol version 2.0; client software version 1.22 sshlib: 
SshMultiExec 1.1
debug1: no match: 1.22 sshlib: SshMultiExec 1.1
Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_3.1p1
debug1: list_hostkey_types: ssh-rsa,ssh-dss
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-
group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-
cbc,arcfour,aes192-cbc,aes256-cbc
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-
cbc,arcfour,aes192-cbc,aes256-cbc
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-
ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-
ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug2: kex_parse_kexinit: diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-dss
debug2: kex_parse_kexinit: aes256-cbc,twofish-cbc,blowfish-cbc,3des-
cbc,arcfour,cast128-cbc
debug2: kex_parse_kexinit: aes256-cbc,twofish-cbc,blowfish-cbc,3des-
cbc,arcfour,cast128-cbc
debug2: kex_parse_kexinit: hmac-sha1,hmac-md5,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-sha1,hmac-md5,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: zlib,none
debug2: kex_parse_kexinit: zlib,none
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug2: mac_init: found hmac-sha1
debug1: kex: client->server aes256-cbc hmac-sha1 zlib
debug2: mac_init: found hmac-sha1
debug1: kex: server->client aes256-cbc hmac-sha1 zlib
debug1: dh_gen_key: priv key bits set: 253/512
debug1: bits set: 510/1024
debug1: expecting SSH2_MSG_KEXDH_INIT
debug1: bits set: 497/1024
debug1: kex_derive_keys
debug1: newkeys: mode 1
debug1: cipher_init: set keylen (16 -> 32)
debug1: Enabling compression at level 6.
debug1: SSH2_MSG_NEWKEYS sent
debug1: waiting for SSH2_MSG_NEWKEYS
debug1: newkeys: mode 0
debug1: cipher_init: set keylen (16 -> 32)
debug1: SSH2_MSG_NEWKEYS received
debug1: KEX done
debug1: userauth-request for user dbider service ssh-connection method password
debug1: attempt 0 failures 0
debug2: input_userauth_request: setting up authctxt for dbider
debug2: input_userauth_request: try method password
Accepted password for dbider from 10.1.1.2 port 2283 ssh2
debug1: Entering interactive session for SSH2.
debug1: fd 3 setting O_NONBLOCK
debug1: fd 7 setting O_NONBLOCK
debug1: server_init_dispatch_20
debug1: server_input_channel_open: ctype session rchan 0 win 20480 max 20480
debug1: input_session_request
debug1: channel 0: new [server-session]
debug1: session_new: init
debug1: session_new: session 0
debug1: session_open: channel 0
debug1: session_open: session 0: link with channel 0
debug1: server_input_channel_open: confirm session
debug1: server_input_channel_req: channel 0 request exec reply 1
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req exec
debug1: fd 9 setting O_NONBLOCK
debug2: fd 9 is O_NONBLOCK
debug1: fd 11 setting O_NONBLOCK
debug1: channel 0: rcvd eof
debug1: channel 0: output open -> drain
debug1: channel 0: obuf empty
debug1: channel 0: close_write
debug1: channel 0: output drain -> closed
debug1: Received SIGCHLD.
debug1: session_by_pid: pid 25454
debug1: session_exit_message: session 0 channel 0 pid 25454
debug1: channel request 0: exit-status
debug1: session_exit_message: release channel 0
debug1: session_close: session 0 pid 25454
debug1: channel 0: read<=0 rfd 9 len 0
debug1: channel 0: read failed
debug1: channel 0: close_read
debug1: channel 0: input open -> drain
debug2: channel 0: read 296 from efd 11
debug1: channel 0: ibuf empty
debug1: channel 0: send eof
debug1: channel 0: input drain -> closed
debug2: channel 0: rwin 20480 elen 296 euse 1
debug2: channel 0: sent ext data 296
debug1: channel 0: send close
debug2: notify_done: reading
debug2: channel 0: read 0 from efd 11
debug2: channel 0: closing read-efd 11
debug3: channel 0: will not send data after close
debug3: channel 0: will not send data after close
Received disconnect from 10.1.1.2: 2: unexpected channel message 6
debug1: Calling cleanup 0x805c800(0x0)
debug1: channel_free: channel 0: server-session, nchannels 1
debug3: channel_free: status: The following connections are open:
  #0 server-session (t4 r0 i3/0 o3/0 fd 9/9)

debug3: channel_close_fds: channel 0: r 9 w 9 e -1
debug1: Calling cleanup 0x8067f40(0x0)
debug1: compress outgoing: raw data 393, compressed 283, factor 0.72
debug1: compress incoming: raw data 183, compressed 171, factor 0.93



------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.