Quoting gilles.lami@kuehne-nagel.com:

> Can you post the result of a "sshd -ddd" (so on the server) after a ssh
> connection ?



The following is the output from secure with sshd running as LOGLEVEL DEBUG3=
;





[root@web01 log]# tail -f --lines=3D0 secure
May 10 14:02:23 web01 sshd[30110]: debug3: fd 4 is not O_NONBLOCK
May 10 14:02:23 web01 sshd[30121]: debug1: rexec start in 4 out 4 =20
newsock 4 pipe 6 sock 7
May 10 14:02:23 web01 sshd[30110]: debug1: Forked child 30121.
May 10 14:02:23 web01 sshd[30110]: debug3: send_rexec_state: entering =20
fd =3D 7 config len 410
May 10 14:02:23 web01 sshd[30110]: debug3: ssh_msg_send: type 0
May 10 14:02:23 web01 sshd[30110]: debug3: send_rexec_state: done
May 10 14:02:23 web01 sshd[30121]: debug1: inetd sockets after dupping: 3, 3
May 10 14:02:23 web01 sshd[30121]: Connection from ::ffff:10.127.5.103 =20
port 4860
May 10 14:02:23 web01 sshd[30121]: debug1: Client protocol version =20
2.0; client software version OpenSSH_4.5
May 10 14:02:23 web01 sshd[30121]: debug1: match: OpenSSH_4.5 pat OpenSSH*
May 10 14:02:23 web01 sshd[30121]: debug1: Enabling compatibility mode =20
for protocol 2.0
May 10 14:02:23 web01 sshd[30121]: debug1: Local version string =20
SSH-2.0-OpenSSH_3.9p1
May 10 14:02:23 web01 sshd[30121]: debug2: fd 3 setting O_NONBLOCK
May 10 14:02:23 web01 sshd[30121]: debug2: Network child is on pid 30122
May 10 14:02:23 web01 sshd[30121]: debug3: preauth child monitor started
May 10 14:02:23 web01 sshd[30122]: debug3: privsep user:group 74:74
May 10 14:02:23 web01 sshd[30121]: debug3: mm_request_receive entering
May 10 14:02:23 web01 sshd[30122]: debug1: permanently_set_uid: 74/74
May 10 14:02:23 web01 sshd[30122]: debug1: list_hostkey_types: ssh-rsa,ssh-d=
ss
May 10 14:02:23 web01 sshd[30122]: debug1: SSH2_MSG_KEXINIT sent
May 10 14:02:23 web01 sshd[30122]: debug1: SSH2_MSG_KEXINIT received
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellma=
n-group1-sha1
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: ssh-rsa,ssh-ds=
s
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,r=
ijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,r=
ijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hm=
ac-md5-96
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hm=
ac-md5-96
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: none,zlib
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: none,zlib
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit:
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit:
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
first_kex_follows 0
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: reserved 0
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diff=
ie-hellman-group14-sha1,diffie-hellman-group1-sha1
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: ssh-rsa,ssh-ds=
s
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,a=
es192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes25=
6-ctr
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,a=
es192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes25=
6-ctr
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hm=
ac-md5-96
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hm=
ac-md5-96
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
none,zlib@openssh.com,zlib
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
none,zlib@openssh.com,zlib
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit:
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit:
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: =20
first_kex_follows 0
May 10 14:02:24 web01 sshd[30122]: debug2: kex_parse_kexinit: reserved 0
May 10 14:02:24 web01 sshd[30122]: debug2: mac_init: found hmac-md5
May 10 14:02:24 web01 sshd[30122]: debug1: kex: client->server =20
aes128-cbc hmac-md5 none
May 10 14:02:24 web01 sshd[30122]: debug2: mac_init: found hmac-md5
May 10 14:02:24 web01 sshd[30122]: debug1: kex: server->client =20
aes128-cbc hmac-md5 none
May 10 14:02:24 web01 sshd[30122]: debug1: SSH2_MSG_KEX_DH_GEX_REQUEST =20
received
May 10 14:02:24 web01 sshd[30122]: debug3: mm_request_send entering: type 0
May 10 14:02:24 web01 sshd[30122]: debug3: mm_choose_dh: waiting for =20
MONITOR_ANS_MODULI
May 10 14:02:24 web01 sshd[30122]: debug3: mm_request_receive_expect =20
entering: type 1
May 10 14:02:24 web01 sshd[30121]: debug3: monitor_read: checking request 0
May 10 14:02:24 web01 sshd[30122]: debug3: mm_request_receive entering
May 10 14:02:24 web01 sshd[30121]: debug3: mm_answer_moduli: got =20
parameters: 1024 1024 8192
May 10 14:02:24 web01 sshd[30121]: debug3: mm_request_send entering: type 1
May 10 14:02:24 web01 sshd[30121]: debug2: monitor_read: 0 used once, =20
disabling now
May 10 14:02:24 web01 sshd[30122]: debug3: mm_choose_dh: remaining 0
May 10 14:02:24 web01 sshd[30121]: debug3: mm_request_receive entering
May 10 14:02:24 web01 sshd[30122]: debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
May 10 14:02:24 web01 sshd[30122]: debug2: dh_gen_key: priv key bits =20
set: 142/256
May 10 14:02:24 web01 sshd[30122]: debug2: bits set: 529/1024
May 10 14:02:24 web01 sshd[30122]: debug1: expecting SSH2_MSG_KEX_DH_GEX_INI=
T
May 10 14:02:24 web01 sshd[30122]: debug2: bits set: 503/1024
May 10 14:02:24 web01 sshd[30122]: debug3: mm_key_sign entering
May 10 14:02:24 web01 sshd[30122]: debug3: mm_request_send entering: type 5
May 10 14:02:24 web01 sshd[30122]: debug3: mm_key_sign: waiting for =20
MONITOR_ANS_SIGN
May 10 14:02:24 web01 sshd[30121]: debug3: monitor_read: checking request 5
May 10 14:02:24 web01 sshd[30122]: debug3: mm_request_receive_expect =20
entering: type 6
May 10 14:02:24 web01 sshd[30121]: debug3: mm_answer_sign
May 10 14:02:24 web01 sshd[30122]: debug3: mm_request_receive entering
May 10 14:02:24 web01 sshd[30121]: debug3: mm_answer_sign: signature =20
0x89a9660(143)
May 10 14:02:24 web01 sshd[30121]: debug3: mm_request_send entering: type 6
May 10 14:02:24 web01 sshd[30121]: debug2: monitor_read: 5 used once, =20
disabling now
May 10 14:02:24 web01 sshd[30122]: debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
May 10 14:02:24 web01 sshd[30121]: debug3: mm_request_receive entering
May 10 14:02:24 web01 sshd[30122]: debug2: kex_derive_keys
May 10 14:02:24 web01 sshd[30122]: debug2: set_newkeys: mode 1
May 10 14:02:24 web01 sshd[30122]: debug1: SSH2_MSG_NEWKEYS sent
May 10 14:02:24 web01 sshd[30122]: debug1: expecting SSH2_MSG_NEWKEYS
May 10 14:02:25 web01 sshd[30122]: debug2: set_newkeys: mode 0
May 10 14:02:25 web01 sshd[30122]: debug1: SSH2_MSG_NEWKEYS received
May 10 14:02:25 web01 sshd[30122]: debug1: KEX done
May 10 14:02:25 web01 sshd[30122]: debug1: userauth-request for user =20
txxxxxx service ssh-connection method none
May 10 14:02:25 web01 sshd[30122]: debug1: attempt 0 failures 0
May 10 14:02:25 web01 sshd[30122]: debug3: mm_getpwnamallow entering
May 10 14:02:25 web01 sshd[30122]: debug3: mm_request_send entering: type 7
May 10 14:02:25 web01 sshd[30122]: debug3: mm_getpwnamallow: waiting =20
for MONITOR_ANS_PWNAM
May 10 14:02:25 web01 sshd[30121]: debug3: monitor_read: checking request 7
May 10 14:02:25 web01 sshd[30122]: debug3: mm_request_receive_expect =20
entering: type 8
May 10 14:02:25 web01 sshd[30121]: debug3: mm_answer_pwnamallow
May 10 14:02:25 web01 sshd[30122]: debug3: mm_request_receive entering
May 10 14:02:25 web01 sshd[30121]: debug3: mm_answer_pwnamallow: =20
sending MONITOR_ANS_PWNAM: 1
May 10 14:02:25 web01 sshd[30121]: debug3: mm_request_send entering: type 8
May 10 14:02:25 web01 sshd[30121]: debug2: monitor_read: 7 used once, =20
disabling now
May 10 14:02:25 web01 sshd[30122]: debug2: input_userauth_request: =20
setting up authctxt for txxxxxx
May 10 14:02:25 web01 sshd[30121]: debug3: mm_request_receive entering
May 10 14:02:25 web01 sshd[30122]: debug3: mm_start_pam entering
May 10 14:02:25 web01 sshd[30122]: debug3: mm_request_send entering: type 46
May 10 14:02:25 web01 sshd[30122]: debug3: mm_inform_authserv entering
May 10 14:02:25 web01 sshd[30121]: debug3: monitor_read: checking request 46
May 10 14:02:25 web01 sshd[30122]: debug3: mm_request_send entering: type 3
May 10 14:02:25 web01 sshd[30121]: debug1: PAM: initializing for "txxxxxx"
May 10 14:02:25 web01 sshd[30122]: debug3: mm_inform_authrole entering
May 10 14:02:25 web01 sshd[30121]: debug3: Normalising mapped IPv4 in =20
IPv6 address
May 10 14:02:25 web01 sshd[30122]: debug3: mm_request_send entering: type 4
May 10 14:02:25 web01 sshd[30121]: debug3: Trying to reverse map =20
address 10.127.5.103.
May 10 14:02:25 web01 sshd[30122]: debug2: input_userauth_request: try =20
method none
May 10 14:02:25 web01 sshd[30121]: debug1: PAM: setting PAM_RHOST to =20
"10.127.5.103"
May 10 14:02:25 web01 sshd[30122]: debug3: mm_auth2_read_banner entering
May 10 14:02:25 web01 sshd[30121]: debug1: PAM: setting PAM_TTY to "ssh"
May 10 14:02:25 web01 sshd[30122]: debug3: mm_request_send entering: type 9
May 10 14:02:25 web01 sshd[30121]: debug2: monitor_read: 46 used once, =20
disabling now
May 10 14:02:25 web01 sshd[30122]: debug3: mm_request_receive_expect =20
entering: type 10
May 10 14:02:25 web01 sshd[30121]: debug3: mm_request_receive entering
May 10 14:02:25 web01 sshd[30122]: debug3: mm_request_receive entering
May 10 14:02:25 web01 sshd[30121]: debug3: monitor_read: checking request 3
May 10 14:02:25 web01 sshd[30121]: debug3: mm_answer_authserv: =20
service=3Dssh-connection, style=3D
May 10 14:02:25 web01 sshd[30121]: debug2: monitor_read: 3 used once, =20
disabling now
May 10 14:02:25 web01 sshd[30121]: debug3: mm_request_receive entering
May 10 14:02:25 web01 sshd[30121]: debug3: monitor_read: checking request 4
May 10 14:02:25 web01 sshd[30121]: debug3: mm_answer_authrole: role=3D
May 10 14:02:25 web01 sshd[30121]: debug2: monitor_read: 4 used once, =20
disabling now
May 10 14:02:25 web01 sshd[30121]: debug3: mm_request_receive entering
May 10 14:02:25 web01 sshd[30121]: debug3: monitor_read: checking request 9
May 10 14:02:25 web01 sshd[30121]: debug3: mm_request_send entering: type 10
May 10 14:02:25 web01 sshd[30121]: debug2: monitor_read: 9 used once, =20
disabling now
May 10 14:02:25 web01 sshd[30122]: debug1: userauth_banner: sent
May 10 14:02:25 web01 sshd[30121]: debug3: mm_request_receive entering
May 10 14:02:25 web01 sshd[30122]: Failed none for txxxxxx from =20
::ffff:10.127.5.103 port 4860 ssh2
May 10 14:02:28 web01 sshd[30122]: debug1: userauth-request for user =20
txxxxxx service ssh-connection method password
May 10 14:02:28 web01 sshd[30122]: debug1: attempt 1 failures 1
May 10 14:02:28 web01 sshd[30122]: debug2: input_userauth_request: try =20
method password
May 10 14:02:28 web01 sshd[30122]: debug3: mm_auth_password entering
May 10 14:02:28 web01 sshd[30122]: debug3: mm_request_send entering: type 11
May 10 14:02:28 web01 sshd[30122]: debug3: mm_auth_password: waiting =20
for MONITOR_ANS_AUTHPASSWORD
May 10 14:02:28 web01 sshd[30122]: debug3: mm_request_receive_expect =20
entering: type 12
May 10 14:02:28 web01 sshd[30121]: debug3: monitor_read: checking request 11
May 10 14:02:28 web01 sshd[30122]: debug3: mm_request_receive entering
May 10 14:02:28 web01 sshd[30121]: debug3: PAM: sshpam_passwd_conv =20
called with 1 messages
May 10 14:02:28 web01 sshd[30121]: debug1: PAM: password =20
authentication accepted for txxxxxx
May 10 14:02:28 web01 sshd[30121]: debug3: mm_answer_authpassword: =20
sending result 1
May 10 14:02:28 web01 sshd[30121]: debug3: mm_request_send entering: type 12
May 10 14:02:28 web01 sshd[30121]: debug3: mm_request_receive_expect =20
entering: type 47
May 10 14:02:28 web01 sshd[30122]: debug3: mm_auth_password: user =20
authenticated
May 10 14:02:28 web01 sshd[30122]: debug3: mm_do_pam_account entering
May 10 14:02:28 web01 sshd[30121]: debug3: mm_request_receive entering
May 10 14:02:28 web01 sshd[30122]: debug3: mm_request_send entering: type 47
May 10 14:02:28 web01 sshd[30122]: debug3: mm_request_receive_expect =20
entering: type 48
May 10 14:02:28 web01 sshd[30122]: debug3: mm_request_receive entering
May 10 14:02:28 web01 sshd[30121]: debug3: PAM: do_pam_account =20
pam_acct_mgmt =3D 0
May 10 14:02:28 web01 sshd[30121]: debug3: mm_request_send entering: type 48
May 10 14:02:28 web01 sshd[30121]: Accepted password for txxxxxx from =20
::ffff:10.127.5.103 port 4860 ssh2
May 10 14:02:28 web01 sshd[30122]: debug3: mm_do_pam_account returning 1
May 10 14:02:28 web01 sshd[30122]: Accepted password for txxxxxx from =20
::ffff:10.127.5.103 port 4860 ssh2
May 10 14:02:28 web01 sshd[30121]: debug1: monitor_child_preauth: =20
txxxxxx has been authenticated by privileged process
May 10 14:02:28 web01 sshd[30121]: debug3: mm_get_keystate: Waiting =20
for new keys
May 10 14:02:28 web01 sshd[30122]: debug3: mm_send_keystate: Sending =20
new keys: 0x89a1300 0x89a1938
May 10 14:02:28 web01 sshd[30121]: debug3: mm_request_receive_expect =20
entering: type 25
May 10 14:02:28 web01 sshd[30122]: debug3: mm_newkeys_to_blob: =20
converting 0x89a1300
May 10 14:02:28 web01 sshd[30121]: debug3: mm_request_receive entering
May 10 14:02:28 web01 sshd[30122]: debug3: mm_newkeys_to_blob: =20
converting 0x89a1938
May 10 14:02:28 web01 sshd[30122]: debug3: mm_send_keystate: New keys =20
have been sent
May 10 14:02:28 web01 sshd[30122]: debug3: mm_send_keystate: Sending =20
compression state
May 10 14:02:28 web01 sshd[30122]: debug3: mm_request_send entering: type 25
May 10 14:02:28 web01 sshd[30122]: debug3: mm_send_keystate: Finished =20
sending state
May 10 14:02:28 web01 sshd[30121]: debug3: mm_newkeys_from_blob: =20
0x8a18ca0(118)
May 10 14:02:28 web01 sshd[30121]: debug2: mac_init: found hmac-md5
May 10 14:02:28 web01 sshd[30121]: debug3: mm_get_keystate: Waiting =20
for second key
May 10 14:02:28 web01 sshd[30121]: debug3: mm_newkeys_from_blob: =20
0x8a18ca0(118)
May 10 14:02:28 web01 sshd[30121]: debug2: mac_init: found hmac-md5
May 10 14:02:28 web01 sshd[30121]: debug3: mm_get_keystate: Getting =20
compression state
May 10 14:02:28 web01 sshd[30121]: debug3: mm_get_keystate: Getting =20
Network I/O buffers
May 10 14:02:28 web01 sshd[30121]: debug3: mm_share_sync: Share sync
May 10 14:02:28 web01 sshd[30121]: debug3: mm_share_sync: Share sync end
May 10 14:02:29 web01 sshd[30121]: debug2: User child is on pid 30124
May 10 14:02:29 web01 sshd[30121]: debug3: mm_request_receive entering
May 10 14:02:34 web01 sshd[30121]: debug1: do_cleanup
May 10 14:02:34 web01 sshd[30121]: debug1: PAM: cleanup
May 10 14:02:34 web01 sshd[30121]: debug3: PAM: sshpam_thread_cleanup enteri=
ng

[root@web01 log]#

----------------------------------------------------------------
This message was sent using IMP, the Internet Messaging Program.