Attachment 947 Details for Bug 1069 – sshd -d traces and ssh -v traces for problem session & one that works

sshd -d traces and ssh -v traces for problem session & one that works

openssh-issue.txt (text/plain), 13.79 KB, created by Steve Hespelt on 2005-08-12 05:00:54 AEST

(hide)

Description:

Filename:

MIME Type:

Creator: Steve Hespelt

Created: 2005-08-12 05:00:54 AEST

Size: 13.79 KB

patch

obsolete

> 
> 
>sshd debug output from using the -e & -D flags: (initial output excluded
>for brevity)
>
>Connection from 147.107.90.11 port 44129
>debug1: Client protocol version 2.0; client software version OpenSSH_4.1
>debug1: match: OpenSSH_4.1 pat OpenSSH*
>debug1: Enabling compatibility mode for protocol 2.0
>debug1: Local version string SSH-1.99-OpenSSH_4.1
>debug2: fd 4 setting O_NONBLOCK
>*** this indicates privsep is being used *** debug2: Network child is on
>pid 2564
>debug3: preauth child monitor started
>debug3: mm_request_receive entering
>debug3: privsep user:group 70804:36001
>debug1: permanently_set_uid: 70804/36001
>debug1: list_hostkey_types: ssh-rsa,ssh-dss
>debug1: SSH2_MSG_KEXINIT sent
>debug1: SSH2_MSG_KEXINIT received
>...
>debug1: ssh_rsa_verify: signature correct
>debug3: mm_answer_keyverify: key 1877f0 signature verified
>debug3: mm_request_send entering: type 23
>Accepted publickey for shespelt from 147.107.90.11 port 44129 ssh2
>debug2: userauth_pubkey: authenticated 1 pkalg ssh-rsa
>debug1: monitor_child_preauth: shespelt has been authenticated by
>privileged process
>debug3: mm_get_keystate: Waiting for new keys
>Accepted publickey for shespelt from 147.107.90.11 port 44129 ssh2
>debug3: mm_request_receive_expect entering: type 24
>debug3: mm_request_receive entering
>debug3: mm_send_keystate: Sending new keys: 164040 16ca80
>debug3: mm_newkeys_to_blob: converting 164040
>debug3: mm_newkeys_to_blob: converting 16ca80
>debug3: mm_send_keystate: New keys have been sent
>debug3: mm_send_keystate: Sending compression state
>debug3: mm_request_send entering: type 24
>debug3: mm_send_keystate: Finished sending state
>debug3: mm_newkeys_from_blob: 164c20(118)
>debug2: mac_init: found hmac-md5
>debug3: mm_get_keystate: Waiting for second key
>debug3: mm_newkeys_from_blob: 164c20(118)
>debug2: mac_init: found hmac-md5
>debug3: mm_get_keystate: Getting compression state
>debug3: mm_get_keystate: Getting Network I/O buffers
>debug3: mm_share_sync: Share sync
>debug3: mm_share_sync: Share sync end
>debug2: set_newkeys: mode 0
>debug2: set_newkeys: mode 1
>debug1: Entering interactive session for SSH2.
>debug2: fd 5 setting O_NONBLOCK
>debug2: fd 6 setting O_NONBLOCK
>debug1: server_init_dispatch_20
>debug1: server_input_channel_open: ctype session rchan 0 win 65536 max
>16384
>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 pty-req reply 0
>debug1: session_by_channel: session 0 channel 0
>debug1: session_input_channel_req: session 0 req pty-req
>debug1: Allocating pty.
>debug1: session_pty_req: session 0 alloc /dev/pts/2
>debug3: tty_parse_modes: SSH2 n_bytes 266
>debug3: tty_parse_modes: ospeed 38400
>debug3: tty_parse_modes: ispeed 0
>debug3: tty_parse_modes: 1 3
>debug3: tty_parse_modes: 2 28
>debug3: tty_parse_modes: 3 8
>debug3: tty_parse_modes: 4 21
>debug3: tty_parse_modes: 5 4
>debug3: tty_parse_modes: 6 0
>debug3: tty_parse_modes: 7 0
>debug3: tty_parse_modes: 8 17
>debug3: tty_parse_modes: 9 19
>debug3: tty_parse_modes: 10 26
>debug3: tty_parse_modes: 11 25
>debug3: tty_parse_modes: 12 18
>debug3: tty_parse_modes: 13 23
>debug3: tty_parse_modes: 14 22
>debug3: tty_parse_modes: 16 0
>debug3: tty_parse_modes: 18 15
>debug3: tty_parse_modes: 30 1
>debug3: tty_parse_modes: 31 0
>debug3: tty_parse_modes: 32 0
>debug3: tty_parse_modes: 33 0
>debug3: tty_parse_modes: 34 0
>debug3: tty_parse_modes: 35 0
>debug3: tty_parse_modes: 36 1
>debug3: tty_parse_modes: 37 0
>debug3: tty_parse_modes: 38 1
>debug3: tty_parse_modes: 39 0
>debug3: tty_parse_modes: 40 0
>debug3: tty_parse_modes: 41 1
>debug3: tty_parse_modes: 50 1
>debug3: tty_parse_modes: 51 1
>debug3: tty_parse_modes: 52 0
>debug3: tty_parse_modes: 53 1
>debug3: tty_parse_modes: 54 1
>debug3: tty_parse_modes: 55 1
>debug3: tty_parse_modes: 56 0
>debug3: tty_parse_modes: 57 0
>debug3: tty_parse_modes: 58 0
>debug3: tty_parse_modes: 59 1
>debug3: tty_parse_modes: 60 1
>debug3: tty_parse_modes: 61 1
>debug3: tty_parse_modes: 62 0
>debug3: tty_parse_modes: 70 1
>debug3: tty_parse_modes: 71 0
>debug3: tty_parse_modes: 72 1
>debug3: tty_parse_modes: 73 0
>debug3: tty_parse_modes: 74 0
>debug3: tty_parse_modes: 75 0
>debug3: tty_parse_modes: 90 1
>debug3: tty_parse_modes: 91 1
>debug3: tty_parse_modes: 92 0
>debug3: tty_parse_modes: 93 0
>debug1: server_input_channel_req: channel 0 request shell reply 0
>debug1: session_by_channel: session 0 channel 0
>debug1: session_input_channel_req: session 0 req shell
>debug2: fd 4 setting TCP_NODELAY
>debug2: fd 9 setting O_NONBLOCK
>debug3: fd 8 is O_NONBLOCK
>*** From channels.c:1377 *** debug2: channel 0: read<=0 rfd 9 len 0
>debug2: channel 0: read failed
>debug2: channel 0: close_read
>debug2: channel 0: input open -> drain
>debug2: channel 0: ibuf empty
>debug2: channel 0: send eof
>debug2: channel 0: input drain -> closed
>debug1: Received SIGCHLD.
>debug1: session_by_pid: pid 2566
>debug1: session_exit_message: session 0 channel 0 pid 2566
>debug2: channel 0: request exit-status confirm 0
>debug1: session_exit_message: release channel 0
>debug2: channel 0: write failed
>debug2: channel 0: close_write
>debug2: channel 0: output open -> closed
>debug1: session_close: session 0 pid 2566
>debug1: session_pty_cleanup: session 0 release /dev/pts/2
>debug2: channel 0: send close
>debug3: channel 0: will not send data after close
>debug2: notify_done: reading
>debug3: channel 0: will not send data after close
>debug2: channel 0: rcvd close
>debug3: channel 0: will not send data after close
>debug2: channel 0: is dead
>debug2: channel 0: garbage collecting
>debug1: channel 0: free: server-session, nchannels 1
>debug3: channel 0: status: The following connections are open:
>  #0 server-session (t4 r0 i3/0 o3/0 fd -1/-1 cfd -1)
>
>debug3: channel 0: close_fds r -1 w -1 e -1 c -1
>Connection closed by 147.107.90.11
>debug1: do_cleanup
>Closing connection to 147.107.90.11
>racssv01:10>
>
>
>Here is my ssh client output :
>racssv12:15> bin/ssh -v -p 2222 shespelt@racssv01
>OpenSSH_4.1p1, OpenSSL 0.9.8 05 Jul 2005
>debug1: Reading configuration data
>/home/shespelt/tools/solaris-2.8/ssh_config
>debug1: Connecting to racssv01 [147.107.90.1] port 2222.
>debug1: Connection established.
>debug1: identity file /home/shespelt/.ssh/identity type -1
>debug1: identity file /home/shespelt/.ssh/id_rsa type 1
>debug1: identity file /home/shespelt/.ssh/id_dsa type -1
>debug1: Remote protocol version 1.99, remote software version
>OpenSSH_4.1
>debug1: match: OpenSSH_4.1 pat OpenSSH*
>debug1: Enabling compatibility mode for protocol 2.0
>debug1: Local version string SSH-2.0-OpenSSH_4.1
>debug1: SSH2_MSG_KEXINIT sent
>debug1: SSH2_MSG_KEXINIT received
>debug1: kex: server->client aes128-cbc hmac-md5 none
>debug1: kex: client->server aes128-cbc hmac-md5 none
>debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent
>debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
>debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
>debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
>debug1: Host 'racssv01' is known and matches the RSA host key.
>debug1: Found key in /home/shespelt/.ssh/known_hosts:5
>debug1: ssh_rsa_verify: signature correct
>debug1: SSH2_MSG_NEWKEYS sent
>debug1: expecting SSH2_MSG_NEWKEYS
>debug1: SSH2_MSG_NEWKEYS received
>debug1: SSH2_MSG_SERVICE_REQUEST sent
>debug1: SSH2_MSG_SERVICE_ACCEPT received
>debug1: Authentications that can continue:
>publickey,password,keyboard-interactive
>debug1: Next authentication method: publickey
>debug1: Trying private key: /home/shespelt/.ssh/identity
>debug1: Offering public key: /home/shespelt/.ssh/id_rsa
>debug1: Server accepts key: pkalg ssh-rsa blen 149
>debug1: read PEM private key done: type RSA
>debug1: Authentication succeeded (publickey).
>debug1: channel 0: new [client-session]
>debug1: Entering interactive session.
>debug3: Trying to reverse map address 147.107.90.11.
>Environment:
>  TZ=US/Eastern
>  SSH_CLIENT=147.107.90.11 44129 2222
>  SSH_CONNECTION=147.107.90.11 44129 147.107.90.1 2222
>  SSH_TTY=/dev/pts/2
>  TERM=vt220
>debug3: channel 0: close_fds r -1 w -1 e -1 c -1
>debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
>debug1: channel 0: free: client-session, nchannels 1
>Connection to racssv01 closed.
>debug1: Transferred: stdin 0, stdout 0, stderr 32 bytes in 0.1 seconds
>debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 254.3
>debug1: Exit status 1
>racssv12:16> 
>
>from the ssh client session that uses the same ssh client but to a different sshd daemon & host:
>[no public key will be used...]
>
>racssv12:10>
>racssv12:10>
>racssv12:10> ./ssh -v -v shespelt@wdlbc08r03
>OpenSSH_4.1p1, OpenSSL 0.9.8 05 Jul 2005
>debug1: Reading configuration data /home/shespelt/tools/solaris-2.8/ssh_config
>debug2: ssh_connect: needpriv 0
>debug1: Connecting to wdlbc08r03 [147.107.90.145] port 22.
>debug1: Connection established.
>debug1: identity file /home/shespelt/.ssh/identity type -1
>debug2: key_type_from_name: unknown key type '-----BEGIN'
>debug2: key_type_from_name: unknown key type '-----END'
>debug1: identity file /home/shespelt/.ssh/id_rsa type 1
>debug2: key_type_from_name: unknown key type '----'
>debug2: key_type_from_name: unknown key type 'Subject:'
>debug2: key_type_from_name: unknown key type 'Comment:'
>debug2: key_type_from_name: unknown key type '----'
>debug1: identity file /home/shespelt/.ssh/id_dsa type -1
>debug1: Remote protocol version 1.99, remote software version OpenSSH_3.6.1p2
>debug1: match: OpenSSH_3.6.1p2 pat OpenSSH_3.*
>debug1: Enabling compatibility mode for protocol 2.0
>debug1: Local version string SSH-2.0-OpenSSH_4.1
>debug2: fd 5 setting O_NONBLOCK
>debug1: SSH2_MSG_KEXINIT sent
>debug1: SSH2_MSG_KEXINIT received
>debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hel
>lman-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-cb
>c,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
>debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cb
>c,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
>debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96
>,hmac-md5-96
>debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@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-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-cb
>c,rijndael-cbc@lysator.liu.se
>debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cb
>c,rijndael-cbc@lysator.liu.se
>debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96
>,hmac-md5-96
>debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@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: mac_init: found hmac-md5
>debug1: kex: server->client aes128-cbc hmac-md5 none
>debug2: mac_init: found hmac-md5
>debug1: kex: client->server aes128-cbc hmac-md5 none
>debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent
>debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
>debug2: dh_gen_key: priv key bits set: 131/256
>debug2: bits set: 501/1024
>debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
>debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
>debug1: Host 'wdlbc08r03' is known and matches the RSA host key.
>debug1: Found key in /home/shespelt/.ssh/known_hosts:1
>debug2: bits set: 508/1024
>debug1: ssh_rsa_verify: signature correct
>debug2: kex_derive_keys
>debug2: set_newkeys: mode 1
>debug1: SSH2_MSG_NEWKEYS sent
>debug1: expecting SSH2_MSG_NEWKEYS
>debug2: set_newkeys: mode 0
>debug1: SSH2_MSG_NEWKEYS received
>debug1: SSH2_MSG_SERVICE_REQUEST sent
>debug2: service_accept: ssh-userauth
>debug1: SSH2_MSG_SERVICE_ACCEPT received
>debug2: key: /home/shespelt/.ssh/identity (0)
>debug2: key: /home/shespelt/.ssh/id_rsa (16c0f8)
>debug2: key: /home/shespelt/.ssh/id_dsa (0)
>debug1: Authentications that can continue: publickey,password,keyboard-interactive
>debug1: Next authentication method: publickey
>debug1: Trying private key: /home/shespelt/.ssh/identity
>debug1: Offering public key: /home/shespelt/.ssh/id_rsa
>debug2: we sent a publickey packet, wait for reply
>debug1: Authentications that can continue: publickey,password,keyboard-interactive
>debug1: Trying private key: /home/shespelt/.ssh/id_dsa
>debug1: PEM_read_PrivateKey failed
>debug1: read PEM private key done: type <unknown>
>Enter passphrase for key '/home/shespelt/.ssh/id_dsa':
>debug2: no passphrase given, try next key
>debug2: we did not send a packet, disable method
>debug1: Next authentication method: keyboard-interactive
>debug2: userauth_kbdint
>debug2: we sent a keyboard-interactive packet, wait for reply
>debug1: Authentications that can continue: publickey,password,keyboard-interactive
>debug2: we did not send a packet, disable method
>debug1: Next authentication method: password
>shespelt@wdlbc08r03's password:
>debug2: we sent a password packet, wait for reply
>debug1: Authentication succeeded (password).
>debug1: channel 0: new [client-session]
>debug2: channel 0: send open
>debug1: Entering interactive session.
>[ at this point the debug info is very different than the above aborted session's debug info ]
>debug2: callback start
>debug2: client_session2_setup: id 0
>debug2: channel 0: request pty-req confirm 0
>debug2: channel 0: request shell confirm 0
>debug2: fd 5 setting TCP_NODELAY
>debug2: callback done
>debug2: channel 0: open confirm rwindow 0 rmax 32768
>debug2: channel 0: rcvd adjust 131072
>wdlbc08r03:1>

Actions: View

Attachments on bug 1069: 947