[7089] in testers
Re: Immediate ssh disconnects
daemon@ATHENA.MIT.EDU (Matthew Belmonte)
Fri Jun 10 09:23:13 2005
Message-Id: <200506101323.j5ADN0un031013@quiche-lorraine.mit.edu>
To: zacheiss@MIT.EDU
cc: ghudson@MIT.EDU, testers@MIT.EDU
MIME-Version: 1.0
Content-Type: multipart/mixed ;
boundary="==_Exmh_16597721240"
Date: Fri, 10 Jun 2005 09:23:00 -0400
From: Matthew Belmonte <belmonte@MIT.EDU>
This is a multipart MIME message.
--==_Exmh_16597721240
Content-Type: text/plain; charset=us-ascii
Attached are two session transcripts, one from the sending machine
(multics.mit.edu running scp) and one from the receiving machine
(quiche-lorraine.mit.edu running /etc/athena/sshd -d), which include two
successful attempts and one failure. The debugging messages reveal heap
corruption being detected at some point after the "temporarily_use_uid"
checkpoint.
Often when I try to replicate this it takes many tries, and it seems to
take especially many tries when debugging is turned on.
--==_Exmh_16597721240
Content-Type: text/plain ; name="receiver.txt"; charset=us-ascii
Content-Description: receiver.txt
Content-Disposition: attachment; filename="receiver.txt"
Script started on Fri 10 Jun 2005 09:04:59 AM EDT
quiche-lorraine.mit.edu# /etc/athena/sshd -d
30578: debug1: sshd version OpenSSH_3.5p1
30578: debug1: private host key: #0 type 0 RSA1
30578: debug1: read PEM private key done: type RSA
30578: debug1: private host key: #1 type 1 RSA
30578: debug1: read PEM private key done: type DSA
30578: debug1: private host key: #2 type 2 DSA
30578: debug1: Bind to port 22 on 0.0.0.0.
30578: Server listening on 0.0.0.0 port 22.
30578: Generating 768 bit RSA key.
30578: RSA key generation complete.
30578: debug1: Server will not fork when running in debugging mode.
30578: Connection from 18.187.1.73 port 34493
30578: debug1: Client protocol version 2.0; client software version OpenSSH_3.5p1
30578: debug1: match: OpenSSH_3.5p1 pat OpenSSH*
30578: debug1: Enabling compatibility mode for protocol 2.0
30578: debug1: Local version string SSH-1.99-OpenSSH_3.5p1
30578: debug1: list_hostkey_types: ssh-rsa,ssh-dss
30578: debug1: SSH2_MSG_KEXINIT sent
30578: debug1: SSH2_MSG_KEXINIT received
30578: debug1: kex: client->server aes128-cbc hmac-md5 none
30578: debug1: kex: server->client aes128-cbc hmac-md5 none
30578: debug1: Wait SSH2_MSG_GSSAPI_INIT
30578: debug1: Received some client credentials
30578: debug1: gss_complete
30578: debug1: dh_gen_key: priv key bits set: 145/256
30578: debug1: bits set: 520/1024
30578: debug1: bits set: 493/1024
30578: debug1: kex_derive_keys
30578: debug1: newkeys: mode 1
30578: debug1: SSH2_MSG_NEWKEYS sent
30578: debug1: waiting for SSH2_MSG_NEWKEYS
30578: debug1: newkeys: mode 0
30578: debug1: SSH2_MSG_NEWKEYS received
30578: debug1: KEX done
30578: debug1: userauth-request for user belmonte service ssh-connection method none
30578: debug1: attempt 0 failures 0
30578: Failed none for belmonte from 18.187.1.73 port 34493 ssh2
30578: debug1: userauth-request for user belmonte service ssh-connection method external-keyx
30578: debug1: attempt 1 failures 1
30578: Authorized to belmonte, krb5 principal belmonte@ATHENA.MIT.EDU (krb5_kuserok)
30578: Accepted external-keyx for belmonte from 18.187.1.73 port 34493 ssh2
30578: debug1: Entering interactive session for SSH2.
30578: debug1: fd 7 setting O_NONBLOCK
30578: debug1: fd 8 setting O_NONBLOCK
30578: debug1: server_init_dispatch_20
30578: debug1: server_input_channel_open: ctype session rchan 0 win 131072 max 32768
30578: debug1: input_session_request
30578: debug1: channel 0: new [server-session]
30578: debug1: session_new: init
30578: debug1: session_new: session 0
30578: debug1: session_open: channel 0
30578: debug1: session_open: session 0: link with channel 0
30578: debug1: server_input_channel_open: confirm session
30578: debug1: server_input_channel_req: channel 0 request exec reply 0
30578: debug1: session_by_channel: session 0 channel 0
30578: debug1: session_input_channel_req: session 0 req exec
30578: debug1: temporarily_use_uid: 3829/101 (e=0/0)
30578: debug1: restore_uid: 0/0
30578: debug1: Received SIGCHLD.
30578: debug1: fd 10 setting O_NONBLOCK
30578: debug1: fd 12 setting O_NONBLOCK
30578: debug1: channel 0: rcvd eof
30578: debug1: channel 0: output open -> drain
30578: debug1: channel 0: obuf empty
30578: debug1: channel 0: close_write
30578: debug1: channel 0: output drain -> closed
30578: debug1: channel 0: read<=0 rfd 10 len 0
30578: debug1: channel 0: read failed
30578: debug1: channel 0: close_read
30578: debug1: channel 0: input open -> drain
30578: debug1: channel 0: ibuf empty
30578: debug1: channel 0: send eof
30578: debug1: channel 0: input drain -> closed
30578: debug1: Received SIGCHLD.
30578: debug1: session_by_pid: pid 30581
30578: debug1: session_exit_message: session 0 channel 0 pid 30581
30578: debug1: channel request 0: exit-status
30578: debug1: session_exit_message: release channel 0
30578: debug1: session_close: session 0 pid 30581
30578: debug1: channel 0: send close
30578: debug1: channel 0: rcvd close
30578: debug1: channel 0: is dead
30578: debug1: channel 0: garbage collecting
30578: debug1: channel_free: channel 0: server-session, nchannels 1
30578: Connection closed by 18.187.1.73
30578: debug1: removing gssapi cred file"/tmp/krb5cc_p30578"
30578: debug1: krb5_cleanup_proc called
30578: Closing connection to 18.187.1.73
quiche-lorraine.mit.edu# !!
/etc/athena/sshd -d
30655: debug1: sshd version OpenSSH_3.5p1
30655: debug1: private host key: #0 type 0 RSA1
30655: debug1: read PEM private key done: type RSA
30655: debug1: private host key: #1 type 1 RSA
30655: debug1: read PEM private key done: type DSA
30655: debug1: private host key: #2 type 2 DSA
30655: debug1: Bind to port 22 on 0.0.0.0.
30655: Server listening on 0.0.0.0 port 22.
30655: Generating 768 bit RSA key.
30655: RSA key generation complete.
30655: debug1: Server will not fork when running in debugging mode.
30655: Connection from 18.187.1.73 port 34494
30655: debug1: Client protocol version 2.0; client software version OpenSSH_3.5p1
30655: debug1: match: OpenSSH_3.5p1 pat OpenSSH*
30655: debug1: Enabling compatibility mode for protocol 2.0
30655: debug1: Local version string SSH-1.99-OpenSSH_3.5p1
30655: debug1: list_hostkey_types: ssh-rsa,ssh-dss
30655: debug1: SSH2_MSG_KEXINIT sent
30655: debug1: SSH2_MSG_KEXINIT received
30655: debug1: kex: client->server aes128-cbc hmac-md5 none
30655: debug1: kex: server->client aes128-cbc hmac-md5 none
30655: debug1: Wait SSH2_MSG_GSSAPI_INIT
30655: debug1: Received some client credentials
30655: debug1: gss_complete
30655: debug1: dh_gen_key: priv key bits set: 126/256
30655: debug1: bits set: 497/1024
30655: debug1: bits set: 524/1024
30655: debug1: kex_derive_keys
30655: debug1: newkeys: mode 1
30655: debug1: SSH2_MSG_NEWKEYS sent
30655: debug1: waiting for SSH2_MSG_NEWKEYS
30655: debug1: newkeys: mode 0
30655: debug1: SSH2_MSG_NEWKEYS received
30655: debug1: KEX done
30655: debug1: userauth-request for user belmonte service ssh-connection method none
30655: debug1: attempt 0 failures 0
30655: Failed none for belmonte from 18.187.1.73 port 34494 ssh2
30655: debug1: userauth-request for user belmonte service ssh-connection method external-keyx
30655: debug1: attempt 1 failures 1
30655: Authorized to belmonte, krb5 principal belmonte@ATHENA.MIT.EDU (krb5_kuserok)
30655: Accepted external-keyx for belmonte from 18.187.1.73 port 34494 ssh2
30655: debug1: Entering interactive session for SSH2.
30655: debug1: fd 7 setting O_NONBLOCK
30655: debug1: fd 8 setting O_NONBLOCK
30655: debug1: server_init_dispatch_20
30655: debug1: server_input_channel_open: ctype session rchan 0 win 131072 max 32768
30655: debug1: input_session_request
30655: debug1: channel 0: new [server-session]
30655: debug1: session_new: init
30655: debug1: session_new: session 0
30655: debug1: session_open: channel 0
30655: debug1: session_open: session 0: link with channel 0
30655: debug1: server_input_channel_open: confirm session
30655: debug1: server_input_channel_req: channel 0 request exec reply 0
30655: debug1: session_by_channel: session 0 channel 0
30655: debug1: session_input_channel_req: session 0 req exec
30655: debug1: temporarily_use_uid: 3829/101 (e=0/0)
30655: debug1: restore_uid: 0/0
30655: debug1: Received SIGCHLD.
30655: debug1: fd 10 setting O_NONBLOCK
30655: debug1: fd 12 setting O_NONBLOCK
30655: debug1: channel 0: rcvd eof
30655: debug1: channel 0: output open -> drain
30655: debug1: channel 0: obuf empty
30655: debug1: channel 0: close_write
30655: debug1: channel 0: output drain -> closed
30655: debug1: Received SIGCHLD.
30655: debug1: session_by_pid: pid 30658
30655: debug1: session_exit_message: session 0 channel 0 pid 30658
30655: debug1: channel request 0: exit-status
30655: debug1: session_exit_message: release channel 0
30655: debug1: session_close: session 0 pid 30658
30655: debug1: channel 0: read<=0 rfd 10 len 0
30655: debug1: channel 0: read failed
30655: debug1: channel 0: close_read
30655: debug1: channel 0: input open -> drain
30655: debug1: channel 0: ibuf empty
30655: debug1: channel 0: send eof
30655: debug1: channel 0: input drain -> closed
30655: debug1: channel 0: send close
30655: debug1: channel 0: rcvd close
30655: debug1: channel 0: is dead
30655: debug1: channel 0: garbage collecting
30655: debug1: channel_free: channel 0: server-session, nchannels 1
30655: Connection closed by 18.187.1.73
30655: debug1: removing gssapi cred file"/tmp/krb5cc_p30655"
30655: debug1: krb5_cleanup_proc called
30655: Closing connection to 18.187.1.73
quiche-lorraine.mit.edu# !!
/etc/athena/sshd -d
30732: debug1: sshd version OpenSSH_3.5p1
30732: debug1: private host key: #0 type 0 RSA1
30732: debug1: read PEM private key done: type RSA
30732: debug1: private host key: #1 type 1 RSA
30732: debug1: read PEM private key done: type DSA
30732: debug1: private host key: #2 type 2 DSA
30732: debug1: Bind to port 22 on 0.0.0.0.
30732: Server listening on 0.0.0.0 port 22.
30732: Generating 768 bit RSA key.
30732: RSA key generation complete.
30732: debug1: Server will not fork when running in debugging mode.
30732: Connection from 18.187.1.73 port 34495
30732: debug1: Client protocol version 2.0; client software version OpenSSH_3.5p1
30732: debug1: match: OpenSSH_3.5p1 pat OpenSSH*
30732: debug1: Enabling compatibility mode for protocol 2.0
30732: debug1: Local version string SSH-1.99-OpenSSH_3.5p1
30732: debug1: list_hostkey_types: ssh-rsa,ssh-dss
30732: debug1: SSH2_MSG_KEXINIT sent
30732: debug1: SSH2_MSG_KEXINIT received
30732: debug1: kex: client->server aes128-cbc hmac-md5 none
30732: debug1: kex: server->client aes128-cbc hmac-md5 none
30732: debug1: Wait SSH2_MSG_GSSAPI_INIT
30732: debug1: Received some client credentials
30732: debug1: gss_complete
30732: debug1: dh_gen_key: priv key bits set: 129/256
30732: debug1: bits set: 513/1024
30732: debug1: bits set: 528/1024
30732: debug1: kex_derive_keys
30732: debug1: newkeys: mode 1
30732: debug1: SSH2_MSG_NEWKEYS sent
30732: debug1: waiting for SSH2_MSG_NEWKEYS
30732: debug1: newkeys: mode 0
30732: debug1: SSH2_MSG_NEWKEYS received
30732: debug1: KEX done
30732: debug1: userauth-request for user belmonte service ssh-connection method none
30732: debug1: attempt 0 failures 0
30732: Failed none for belmonte from 18.187.1.73 port 34495 ssh2
30732: debug1: userauth-request for user belmonte service ssh-connection method external-keyx
30732: debug1: attempt 1 failures 1
30732: Authorized to belmonte, krb5 principal belmonte@ATHENA.MIT.EDU (krb5_kuserok)
30732: Accepted external-keyx for belmonte from 18.187.1.73 port 34495 ssh2
30732: debug1: Entering interactive session for SSH2.
30732: debug1: fd 7 setting O_NONBLOCK
30732: debug1: fd 8 setting O_NONBLOCK
30732: debug1: server_init_dispatch_20
30732: debug1: server_input_channel_open: ctype session rchan 0 win 131072 max 32768
30732: debug1: input_session_request
30732: debug1: channel 0: new [server-session]
30732: debug1: session_new: init
30732: debug1: session_new: session 0
30732: debug1: session_open: channel 0
30732: debug1: session_open: session 0: link with channel 0
30732: debug1: server_input_channel_open: confirm session
30732: debug1: server_input_channel_req: channel 0 request exec reply 0
30732: debug1: session_by_channel: session 0 channel 0
30732: debug1: session_input_channel_req: session 0 req exec
30732: debug1: temporarily_use_uid: 3829/101 (e=0/0)
*** glibc detected *** double free or corruption (fasttop): 0x08375388 ***
Aborted
quiche-lorraine.mit.edu# exit
exit
Script done on Fri 10 Jun 2005 09:06:12 AM EDT
--==_Exmh_16597721240
Content-Type: text/plain ; name="sender.txt"; charset=us-ascii
Content-Description: sender.txt
Content-Disposition: attachment; filename="sender.txt"
Script started on Fri Jun 10 09:05:25 2005
multics% scp foo keesh:/tmp
30581: debug1: permanently_set_uid: 3829/101
30581: debug1: Setting KRB5CCNAME to FILE:/tmp/krb5cc_p30578
Environment:
KRB5CCNAME=/tmp/krb5cc_p30578
USER=belmonte
LOGNAME=belmonte
HOME=/mit/belmonte
PATH=/usr/athena/bin:/bin/athena:/usr/bin:/bin:/usr/sbin:/sbin
MAIL=/var/mail/belmonte
SHELL=/bin/athena/tcsh
SSH_CLIENT=18.187.1.73 34493 22
SSH_CONNECTION=18.187.1.73 34493 18.187.1.71 22
KRBTKFILE=/tmp/tkt_p30578
XAUTHORITY=/tmp/xauth-belmonte-30581/Xauthority
foo 0% | | 0 --:-- ETAfoo 100% |*****************************| 4 00:00
multics% !!
scp foo keesh:/tmp
30658: debug1: permanently_set_uid: 3829/101
30658: debug1: Setting KRB5CCNAME to FILE:/tmp/krb5cc_p30655
Environment:
KRB5CCNAME=/tmp/krb5cc_p30655
USER=belmonte
LOGNAME=belmonte
HOME=/mit/belmonte
PATH=/usr/athena/bin:/bin/athena:/usr/bin:/bin:/usr/sbin:/sbin
MAIL=/var/mail/belmonte
SHELL=/bin/athena/tcsh
SSH_CLIENT=18.187.1.73 34494 22
SSH_CONNECTION=18.187.1.73 34494 18.187.1.71 22
KRBTKFILE=/tmp/tkt_p30655
XAUTHORITY=/tmp/xauth-belmonte-30658/Xauthority
foo 0% | | 0 --:-- ETAfoo 100% |*****************************| 4 00:00
multics% !!
scp foo keesh:/tmp
Connection to keesh closed by remote host.
lost connection
multics% exit
script done on Fri Jun 10 09:06:14 2005
--==_Exmh_16597721240--
