I do not have any ideas on this.
Where should I start.
[root@192.168.1.80 security]# date && time ssh -v 192.168.1.21 date Fri May 23 11:43:53 EDT 2008 OpenSSH_3.9p1, OpenSSL 0.9.7a Feb 19 2003 debug1: Reading configuration data /root/.ssh/config debug1: Applying options for 192.168.1.21 debug1: Reading configuration data /etc/ssh/ssh_config debug1: Applying options for * debug1: Connecting to 192.168.1.21 [192.168.1.21] port 22. debug1: Connection established. debug1: permanently_set_uid: 0/0 debug1: identity file /root/.ssh/identity type -1 debug1: identity file /root/.ssh/id_rsa type -1 debug1: identity file /root/.ssh/id_dsa type 2 debug1: Remote protocol version 1.99, remote software version OpenSSH_4.6 debug1: match: OpenSSH_4.6 pat OpenSSH* debug1: Enabling compatibility mode for protocol 2.0 debug1: Local version string SSH-2.0-OpenSSH_3.9p1 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 '192.168.1.21' is known and matches the RSA host key. debug1: Found key in /root/.ssh/known_hosts:4 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
Paused 9 seconds.
debug1: Authentications that can continue: publickey,password debug1: Next authentication method: publickey debug1: Trying private key: /root/.ssh/identity debug1: Trying private key: /root/.ssh/id_rsa debug1: Offering public key: /root/.ssh/id_dsa debug1: Server accepts key: pkalg ssh-dss blen 433 debug1: read PEM private key done: type DSA
Paused 9 seconds.
debug1: Authentication succeeded (publickey). debug1: channel 0: new [client-session] debug1: Entering interactive session.
Paused 16 seconds.
debug1: Sending command: echo
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0 debug1: channel 0: free: client-session, nchannels 1 debug1: Transferred: stdin 0, stdout 0, stderr 0 bytes in 13.5 seconds debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 0.0 debug1: Exit status 0
real 0m34.027s user 0m0.014s sys 0m0.083s Fri May 23 11:51:32 EDT 2008 [root@statics31 security]#
And the log from 192.168.1.21 (different run so the dates won't match):
==> /var/log/secure <== May 23 12:01:56 192.168.1.21 pam_stack[23836]: called for "PAM_ACCOUNT" May 23 12:01:56 192.168.1.21 pam_stack[23836]: called from "sshd" May 23 12:01:56 192.168.1.21 pam_stack[23836]: initializing May 23 12:01:56 192.168.1.21 pam_stack[23836]: creating child stack `system-auth' May 23 12:01:56 192.168.1.21 pam_stack[23836]: creating environment May 23 12:01:56 192.168.1.21 pam_stack[23836]: NOT passing PAM_AUTHTOK to child: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing PAM_CONV to child May 23 12:01:56 192.168.1.21 pam_stack[23836]: NOT passing PAM_FAIL_DELAY to child: source not set May 23 12:01:56 192.168.1.21 pam_stack[23836]: NOT passing PAM_OLDAUTHTOK to child: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing PAM_RHOST to child May 23 12:01:56 192.168.1.21 pam_stack[23836]: NOT passing PAM_RUSER to child: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing PAM_SERVICE to child May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing PAM_TTY to child May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing PAM_USER to child May 23 12:01:56 192.168.1.21 pam_stack[23836]: NOT passing PAM_USER_PROMPT to child: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing data to child May 23 12:01:56 192.168.1.21 pam_stack[23836]: calling substack May 23 12:01:56 192.168.1.21 pam_stack[23836]: substack returned 0 (Success) May 23 12:01:56 192.168.1.21 pam_stack[23836]: NOT passing PAM_AUTHTOK to parent: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing PAM_CONV to parent May 23 12:01:56 192.168.1.21 pam_stack[23836]: NOT passing PAM_FAIL_DELAY to parent: source not set May 23 12:01:56 192.168.1.21 pam_stack[23836]: NOT passing PAM_OLDAUTHTOK to parent: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing PAM_RHOST to parent May 23 12:01:56 192.168.1.21 pam_stack[23836]: NOT passing PAM_RUSER to parent: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing PAM_SERVICE to parent May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing PAM_TTY to parent May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing PAM_USER to parent May 23 12:01:56 192.168.1.21 pam_stack[23836]: NOT passing PAM_USER_PROMPT to parent: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing data back May 23 12:01:56 192.168.1.21 pam_stack[23836]: passing former back May 23 12:01:56 192.168.1.21 pam_stack[23836]: returning 0 (Success) May 23 12:01:56 192.168.1.21 pam_stack[23844]: called for "PAM_OPEN_SESSION" May 23 12:01:56 192.168.1.21 pam_stack[23844]: called from "sshd" May 23 12:01:56 192.168.1.21 pam_stack[23844]: initializing May 23 12:01:56 192.168.1.21 pam_stack[23844]: found previously-used child stack `system-auth' May 23 12:01:56 192.168.1.21 pam_stack[23844]: NOT passing PAM_AUTHTOK to child: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing PAM_CONV to child May 23 12:01:56 192.168.1.21 pam_stack[23844]: NOT passing PAM_FAIL_DELAY to child: source not set May 23 12:01:56 192.168.1.21 pam_stack[23844]: NOT passing PAM_OLDAUTHTOK to child: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing PAM_RHOST to child May 23 12:01:56 192.168.1.21 pam_stack[23844]: NOT passing PAM_RUSER to child: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing PAM_SERVICE to child May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing PAM_TTY to child May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing PAM_USER to child May 23 12:01:56 192.168.1.21 pam_stack[23844]: NOT passing PAM_USER_PROMPT to child: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing data to child May 23 12:01:56 192.168.1.21 pam_stack[23844]: calling substack May 23 12:01:56 192.168.1.21 pam_stack[23844]: substack returned 0 (Success) May 23 12:01:56 192.168.1.21 pam_stack[23844]: NOT passing PAM_AUTHTOK to parent: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing PAM_CONV to parent May 23 12:01:56 192.168.1.21 pam_stack[23844]: NOT passing PAM_FAIL_DELAY to parent: source not set May 23 12:01:56 192.168.1.21 pam_stack[23844]: NOT passing PAM_OLDAUTHTOK to parent: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing PAM_RHOST to parent May 23 12:01:56 192.168.1.21 pam_stack[23844]: NOT passing PAM_RUSER to parent: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing PAM_SERVICE to parent May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing PAM_TTY to parent May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing PAM_USER to parent May 23 12:01:56 192.168.1.21 pam_stack[23844]: NOT passing PAM_USER_PROMPT to parent: source is NULL May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing data back May 23 12:01:56 192.168.1.21 pam_stack[23844]: passing former back May 23 12:01:56 192.168.1.21 pam_stack[23844]: returning 0 (Success)
==> /var/log/messages <== May 23 12:01:56 192.168.1.21 sshd[23836]: Accepted publickey for root from 192.168.1.80 port 39910 ssh2 May 23 12:01:56 192.168.1.21 sshd(pam_unix)[23844]: session opened for user root by (uid=0)
==> /var/log/secure <== May 23 12:02:01 192.168.1.21 pam_stack[23844]: called for "PAM_SETCRED" May 23 12:02:01 192.168.1.21 pam_stack[23844]: called from "sshd" May 23 12:02:01 192.168.1.21 pam_stack[23844]: initializing May 23 12:02:01 192.168.1.21 pam_stack[23844]: found previously-used child stack `system-auth' May 23 12:02:01 192.168.1.21 pam_stack[23844]: NOT passing PAM_AUTHTOK to child: source is NULL May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing PAM_CONV to child May 23 12:02:01 192.168.1.21 pam_stack[23844]: NOT passing PAM_FAIL_DELAY to child: source not set May 23 12:02:01 192.168.1.21 pam_stack[23844]: NOT passing PAM_OLDAUTHTOK to child: source is NULL May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing PAM_RHOST to child May 23 12:02:01 192.168.1.21 pam_stack[23844]: NOT passing PAM_RUSER to child: source is NULL May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing PAM_SERVICE to child May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing PAM_TTY to child May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing PAM_USER to child May 23 12:02:01 192.168.1.21 pam_stack[23844]: NOT passing PAM_USER_PROMPT to child: source is NULL May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing data to child May 23 12:02:01 192.168.1.21 pam_stack[23844]: calling substack May 23 12:02:01 192.168.1.21 pam_stack[23844]: substack returned 0 (Success) May 23 12:02:01 192.168.1.21 pam_stack[23844]: NOT passing PAM_AUTHTOK to parent: source is NULL May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing PAM_CONV to parent May 23 12:02:01 192.168.1.21 pam_stack[23844]: NOT passing PAM_FAIL_DELAY to parent: source not set May 23 12:02:01 192.168.1.21 pam_stack[23844]: NOT passing PAM_OLDAUTHTOK to parent: source is NULL May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing PAM_RHOST to parent May 23 12:02:01 192.168.1.21 pam_stack[23844]: NOT passing PAM_RUSER to parent: source is NULL May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing PAM_SERVICE to parent May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing PAM_TTY to parent May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing PAM_USER to parent May 23 12:02:01 192.168.1.21 pam_stack[23844]: NOT passing PAM_USER_PROMPT to parent: source is NULL May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing data back May 23 12:02:01 192.168.1.21 pam_stack[23844]: passing former back May 23 12:02:01 192.168.1.21 pam_stack[23844]: returning 0 (Success)
==> /var/log/messages <== May 23 12:02:16 192.168.1.21 sshd[23844]: error: channel 0: chan_read_failed for istate 3
==> /var/log/secure <== May 23 12:02:16 192.168.1.21 pam_stack[23844]: called for "PAM_SETCRED" May 23 12:02:16 192.168.1.21 pam_stack[23844]: called from "sshd" May 23 12:02:16 192.168.1.21 pam_stack[23844]: initializing May 23 12:02:16 192.168.1.21 pam_stack[23844]: found previously-used child stack `system-auth' May 23 12:02:16 192.168.1.21 pam_stack[23844]: NOT passing PAM_AUTHTOK to child: source is NULL May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing PAM_CONV to child May 23 12:02:16 192.168.1.21 pam_stack[23844]: NOT passing PAM_FAIL_DELAY to child: source not set May 23 12:02:16 192.168.1.21 pam_stack[23844]: NOT passing PAM_OLDAUTHTOK to child: source is NULL May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing PAM_RHOST to child May 23 12:02:16 192.168.1.21 pam_stack[23844]: NOT passing PAM_RUSER to child: source is NULL May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing PAM_SERVICE to child May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing PAM_TTY to child May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing PAM_USER to child May 23 12:02:16 192.168.1.21 pam_stack[23844]: NOT passing PAM_USER_PROMPT to child: source is NULL May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing data to child May 23 12:02:16 192.168.1.21 pam_stack[23844]: calling substack May 23 12:02:16 192.168.1.21 pam_stack[23844]: substack returned 0 (Success) May 23 12:02:16 192.168.1.21 pam_stack[23844]: NOT passing PAM_AUTHTOK to parent: source is NULL May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing PAM_CONV to parent May 23 12:02:16 192.168.1.21 pam_stack[23844]: NOT passing PAM_FAIL_DELAY to parent: source not set May 23 12:02:16 192.168.1.21 pam_stack[23844]: NOT passing PAM_OLDAUTHTOK to parent: source is NULL May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing PAM_RHOST to parent May 23 12:02:16 192.168.1.21 pam_stack[23844]: NOT passing PAM_RUSER to parent: source is NULL May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing PAM_SERVICE to parent May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing PAM_TTY to parent May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing PAM_USER to parent May 23 12:02:16 192.168.1.21 pam_stack[23844]: NOT passing PAM_USER_PROMPT to parent: source is NULL May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing data back May 23 12:02:16 192.168.1.21 pam_stack[23844]: passing former back May 23 12:02:16 192.168.1.21 pam_stack[23844]: returning 0 (Success) May 23 12:02:21 192.168.1.21 pam_stack[23844]: called for "PAM_CLOSE_SESSION" May 23 12:02:21 192.168.1.21 pam_stack[23844]: called from "sshd" May 23 12:02:21 192.168.1.21 pam_stack[23844]: initializing May 23 12:02:21 192.168.1.21 pam_stack[23844]: found previously-used child stack `system-auth' May 23 12:02:21 192.168.1.21 pam_stack[23844]: NOT passing PAM_AUTHTOK to child: source is NULL May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing PAM_CONV to child May 23 12:02:21 192.168.1.21 pam_stack[23844]: NOT passing PAM_FAIL_DELAY to child: source not set May 23 12:02:21 192.168.1.21 pam_stack[23844]: NOT passing PAM_OLDAUTHTOK to child: source is NULL May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing PAM_RHOST to child May 23 12:02:21 192.168.1.21 pam_stack[23844]: NOT passing PAM_RUSER to child: source is NULL May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing PAM_SERVICE to child May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing PAM_TTY to child May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing PAM_USER to child May 23 12:02:21 192.168.1.21 pam_stack[23844]: NOT passing PAM_USER_PROMPT to child: source is NULL May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing data to child May 23 12:02:21 192.168.1.21 pam_stack[23844]: calling substack May 23 12:02:21 192.168.1.21 pam_stack[23844]: substack returned 0 (Success) May 23 12:02:21 192.168.1.21 pam_stack[23844]: NOT passing PAM_AUTHTOK to parent: source is NULL May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing PAM_CONV to parent May 23 12:02:21 192.168.1.21 pam_stack[23844]: NOT passing PAM_FAIL_DELAY to parent: source not set May 23 12:02:21 192.168.1.21 pam_stack[23844]: NOT passing PAM_OLDAUTHTOK to parent: source is NULL May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing PAM_RHOST to parent May 23 12:02:21 192.168.1.21 pam_stack[23844]: NOT passing PAM_RUSER to parent: source is NULL May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing PAM_SERVICE to parent May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing PAM_TTY to parent May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing PAM_USER to parent May 23 12:02:21 192.168.1.21 pam_stack[23844]: NOT passing PAM_USER_PROMPT to parent: source is NULL May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing data back May 23 12:02:21 192.168.1.21 pam_stack[23844]: passing former back May 23 12:02:21 192.168.1.21 pam_stack[23844]: returning 0 (Success)
==> /var/log/messages <== May 23 12:02:16 192.168.1.21 last message repeated 2 times May 23 12:02:21 192.168.1.21 sshd(pam_unix)[23844]: session closed for user root
-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- - - - Jason Pyeron PD Inc. http://www.pdinc.us - - Principal Consultant 10 West 24th Street #100 - - +1 (443) 269-1555 x333 Baltimore, Maryland 21218 - - - -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-
This message is for the designated recipient only and may contain privileged, proprietary, or otherwise private information. If you have received it in error, purge the message from your system and notify the sender immediately. Any other use of the email by you is prohibited.
On Fri, 23 May 2008, Jason Pyeron wrote:
I do not have any ideas on this.
Where should I start. [... lots and lots of snippage ...]
When sshd looks to be the culprit, my troubleshooting begins by launching it in foreground mode on a non-standard port on the server:
sshd -ddd -p 2222
On the client, do
ssh -p 2222 your.server
If that doesn't provide good info, wrap sshd in strace:
strace -o /tmp/sshd-trace.txt sshd -d -p 2222
The strace output will show where the delays are occuring. (You can modify timestamp info in the strace output. See the man page for details.)
-----Original Message----- From: centos-bounces@centos.org [mailto:centos-bounces@centos.org] On Behalf Of Paul Heinlein Sent: Friday, May 23, 2008 1:06 PM
When sshd looks to be the culprit, my troubleshooting begins by launching it in foreground mode on a non-standard port on the server:
sshd -ddd -p 2222
Will snip in reply to this. Putting it in full just in case.
[root@192.168.1.21 ~]# /usr/sbin/sshd -ddd -p 22222 debug2: load_server_config: filename /etc/ssh/sshd_config debug2: load_server_config: done config len = 191 debug2: parse_server_config: config /etc/ssh/sshd_config len 191 debug3: /etc/ssh/sshd_config:86 setting UsePAM yes debug3: /etc/ssh/sshd_config:89 setting GatewayPorts yes debug3: /etc/ssh/sshd_config:111 setting Subsystem sftp /usr/libexec/openssh/sftp-server debug1: sshd version OpenSSH_4.6p1 debug1: private host key: #0 type 0 RSA1 debug3: Not a RSA1 key file /etc/ssh/ssh_host_rsa_key. debug1: read PEM private key done: type RSA debug1: private host key: #1 type 1 RSA debug3: Not a RSA1 key file /etc/ssh/ssh_host_dsa_key. debug1: read PEM private key done: type DSA debug1: private host key: #2 type 2 DSA debug1: rexec_argv[0]='/usr/sbin/sshd' debug1: rexec_argv[1]='-ddd' debug1: rexec_argv[2]='-p' debug1: rexec_argv[3]='22222' debug2: fd 3 setting O_NONBLOCK debug1: Bind to port 22222 on ::. Server listening on :: port 22222. debug2: fd 4 setting O_NONBLOCK debug1: Bind to port 22222 on 0.0.0.0. Bind to port 22222 on 0.0.0.0 failed: Address already in use. Generating 768 bit RSA key. RSA key generation complete. debug3: fd 4 is not O_NONBLOCK debug1: Server will not fork when running in debugging mode. debug3: send_rexec_state: entering fd = 7 config len 191 debug3: ssh_msg_send: type 0 debug3: send_rexec_state: done debug1: rexec start in 4 out 4 newsock 4 pipe -1 sock 7 debug1: inetd sockets after dupping: 3, 3 debug3: Normalising mapped IPv4 in IPv6 address debug3: Normalising mapped IPv4 in IPv6 address Connection from 192.168.1.80 port 40084 debug1: Client protocol version 2.0; client software version OpenSSH_3.9p1 debug1: match: OpenSSH_3.9p1 pat OpenSSH_3.* debug1: Enabling compatibility mode for protocol 2.0 debug1: Local version string SSH-1.99-OpenSSH_4.6 debug2: fd 3 setting O_NONBLOCK debug3: privsep user:group 74:74 debug1: permanently_set_uid: 74/74 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-sha256,diffie-hellman-group-exchange-sha1,diff ie-hellman-group14-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,arcfour128,arcfour256,arcfour,a es192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes25 6-ctr debug2: kex_parse_kexinit: 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 debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hm ac-md5-96 debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hm ac-md5-96 debug2: kex_parse_kexinit: none,zlib@openssh.com debug2: kex_parse_kexinit: none,zlib@openssh.com 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-group14-sha1,diffie-hellma n-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,r ijndael-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-cbc,r ijndael-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,hm ac-md5-96 debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hm ac-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 debug2: Network child is on pid 25687 debug3: preauth child monitor started debug3: mm_request_receive entering debug1: kex: client->server aes128-cbc hmac-md5 none debug2: mac_init: found hmac-md5 debug1: kex: server->client aes128-cbc hmac-md5 none debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received debug3: mm_request_send entering: type 0 debug3: monitor_read: checking request 0 debug3: mm_answer_moduli: got parameters: 1024 1024 8192 debug3: mm_request_send entering: type 1 debug2: monitor_read: 0 used once, disabling now debug3: mm_request_receive entering debug3: mm_choose_dh: waiting for MONITOR_ANS_MODULI debug3: mm_request_receive_expect entering: type 1 debug3: mm_request_receive entering debug3: mm_choose_dh: remaining 0 debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent debug2: dh_gen_key: priv key bits set: 116/256 debug2: bits set: 514/1024 debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT debug2: bits set: 514/1024 debug3: mm_key_sign entering debug3: mm_request_send entering: type 4 debug3: monitor_read: checking request 4 debug3: mm_answer_sign debug3: mm_answer_sign: signature 0x660ac0(143) debug3: mm_request_send entering: type 5 debug2: monitor_read: 4 used once, disabling now debug3: mm_request_receive entering debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN debug3: mm_request_receive_expect entering: type 5 debug3: mm_request_receive entering debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent 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: KEX done debug1: userauth-request for user root service ssh-connection method none debug1: attempt 0 failures 0 debug3: mm_getpwnamallow entering debug3: mm_request_send entering: type 6 debug3: monitor_read: checking request 6 debug3: mm_answer_pwnamallow debug3: Normalising mapped IPv4 in IPv6 address debug3: Trying to reverse map address 192.168.1.80.
paused 7 seconds
debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM debug3: mm_request_receive_expect entering: type 7 debug3: mm_request_receive entering debug2: parse_server_config: config reprocess config len 191 debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1 debug3: mm_request_send entering: type 7 debug2: monitor_read: 6 used once, disabling now debug3: mm_request_receive entering debug2: input_userauth_request: setting up authctxt for root debug3: mm_start_pam entering debug3: mm_request_send entering: type 45 debug3: mm_inform_authserv entering debug3: mm_request_send entering: type 3 debug2: input_userauth_request: try method none debug3: mm_auth_password entering debug3: mm_request_send entering: type 10 debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD debug3: mm_request_receive_expect entering: type 11 debug3: mm_request_receive entering debug3: monitor_read: checking request 45 debug1: PAM: initializing for "root" debug1: PAM: setting PAM_RHOST to "host80.1.internal.pdinc.us" debug1: PAM: setting PAM_TTY to "ssh" debug2: monitor_read: 45 used once, disabling now debug3: mm_request_receive entering debug3: monitor_read: checking request 3 debug3: mm_answer_authserv: service=ssh-connection, style= debug2: monitor_read: 3 used once, disabling now debug3: mm_request_receive entering debug3: monitor_read: checking request 10 debug3: mm_answer_authpassword: sending result 0 debug3: mm_request_send entering: type 11 debug3: mm_auth_password: user not authenticated Failed none for root from 192.168.1.80 port 40084 ssh2 debug3: mm_request_receive entering debug1: userauth-request for user root service ssh-connection method publickey debug1: attempt 1 failures 1 debug2: input_userauth_request: try method publickey debug1: test whether pkalg/pkblob are acceptable debug3: mm_key_allowed entering debug3: mm_request_send entering: type 20 debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED debug3: mm_request_receive_expect entering: type 21 debug3: mm_request_receive entering debug3: monitor_read: checking request 20 debug3: mm_answer_keyallowed entering debug3: mm_answer_keyallowed: key_from_blob: 0x6f4240 debug1: temporarily_use_uid: 11001/504 (e=0/0) debug1: trying public key file /root/.ssh/authorized_keys debug3: secure_filename: checking '/root/.ssh' debug3: secure_filename: checking '/root' debug3: secure_filename: terminating check at '/root' debug1: matching key found: file /root/.ssh/authorized_keys, line 1 Found matching DSA key: f0:aa:c8:ee:46:67:f1:88:f9:21:46:ab:f6:2c:29:31 debug1: restore_uid: 0/0 debug3: mm_answer_keyallowed: key 0x6f4240 is allowed debug3: mm_request_send entering: type 21 debug3: mm_request_receive entering debug2: userauth_pubkey: authenticated 0 pkalg ssh-dss Postponed publickey for root from 192.168.1.80 port 40084 ssh2 debug1: userauth-request for user root service ssh-connection method publickey debug1: attempt 2 failures 1 debug2: input_userauth_request: try method publickey debug3: mm_key_allowed entering debug3: mm_request_send entering: type 20 debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED debug3: mm_request_receive_expect entering: type 21 debug3: mm_request_receive entering debug3: monitor_read: checking request 20 debug3: mm_answer_keyallowed entering debug3: mm_answer_keyallowed: key_from_blob: 0x6f3210 debug1: temporarily_use_uid: 11001/504 (e=0/0) debug1: trying public key file /root/.ssh/authorized_keys debug3: secure_filename: checking '/root/.ssh' debug3: secure_filename: checking '/root' debug3: secure_filename: terminating check at '/root' debug1: matching key found: file /root/.ssh/authorized_keys, line 1 Found matching DSA key: f0:aa:c8:ee:46:67:f1:88:f9:21:46:ab:f6:2c:29:31 debug1: restore_uid: 0/0 debug3: mm_answer_keyallowed: key 0x6f3210 is allowed debug3: mm_request_send entering: type 21 debug3: mm_request_receive entering debug3: mm_key_verify entering debug3: mm_request_send entering: type 22 debug3: mm_key_verify: waiting for MONITOR_ANS_KEYVERIFY debug3: mm_request_receive_expect entering: type 23 debug3: mm_request_receive entering debug3: monitor_read: checking request 22 debug1: ssh_dss_verify: signature correct debug3: mm_answer_keyverify: key 0x6f4390 signature verified debug3: mm_request_send entering: type 23 debug3: mm_request_receive_expect entering: type 46 debug2: userauth_pubkey: authenticated 1 pkalg ssh-dss debug3: mm_do_pam_account entering debug3: mm_request_send entering: type 46 debug3: mm_request_receive_expect entering: type 47 debug3: mm_request_receive entering debug3: mm_request_receive entering debug1: do_pam_account: called
pause 7 seconds
debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success) debug3: mm_request_send entering: type 47 Accepted publickey for root from 192.168.1.80 port 40084 ssh2 debug1: monitor_child_preauth: root has been authenticated by privileged process debug3: mm_get_keystate: Waiting for new keys debug3: mm_request_receive_expect entering: type 24 debug3: mm_request_receive entering debug3: mm_do_pam_account returning 1 debug3: mm_send_keystate: Sending new keys: 0x65dc40 0x65dbc0 debug3: mm_newkeys_to_blob: converting 0x65dc40 debug3: mm_newkeys_to_blob: converting 0x65dbc0 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: 0x6faeb0(122) debug2: mac_init: found hmac-md5 debug3: mm_get_keystate: Waiting for second key debug3: mm_newkeys_from_blob: 0x6faeb0(122) 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: User child is on pid 25688 debug3: mm_request_receive entering debug3: PAM: opening session
pause 7 seconds
debug1: PAM: reinitializing credentials
pause 20 seconds
debug1: permanently_set_uid: 0/0 debug2: set_newkeys: mode 0 debug2: set_newkeys: mode 1 debug1: Entering interactive session for SSH2. debug2: fd 6 setting O_NONBLOCK debug2: fd 9 setting O_NONBLOCK debug1: server_init_dispatch_20 debug1: server_input_channel_open: ctype session rchan 0 win 131072 max 32768 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 0 debug1: session_by_channel: session 0 channel 0 debug1: session_input_channel_req: session 0 req exec debug2: fd 3 setting TCP_NODELAY debug2: fd 11 setting O_NONBLOCK debug3: fd 11 is O_NONBLOCK debug2: fd 13 setting O_NONBLOCK debug2: channel 0: read 49 from efd 13 debug2: channel 0: rwin 131072 elen 49 euse 1 debug2: channel 0: sent ext data 49 debug2: channel 0: read 13 from efd 13 debug2: channel 0: rwin 131023 elen 13 euse 1 debug2: channel 0: sent ext data 13 debug2: channel 0: read 17 from efd 13 debug2: channel 0: rwin 131010 elen 17 euse 1 debug2: channel 0: sent ext data 17 debug2: channel 0: read 267 from efd 13 debug2: channel 0: rwin 130993 elen 267 euse 1 debug2: channel 0: sent ext data 267 debug2: channel 0: read failed debug2: channel 0: close_read debug2: channel 0: input open -> drain debug2: channel 0: ibuf_empty delayed efd 13/(0) debug2: notify_done: reading debug1: Received SIGCHLD. debug1: session_by_pid: pid 25696 debug1: session_exit_message: session 0 channel 0 pid 25696 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 debug2: channel 0: read<=0 rfd 11 len 0 debug2: channel 0: read failed channel 0: chan_read_failed for istate 1 debug2: channel 0: read 0 from efd 13 debug2: channel 0: closing read-efd 13 debug2: channel 0: ibuf empty debug2: channel 0: send eof debug2: channel 0: input drain -> closed debug2: channel 0: send close debug2: channel 0: read<=0 rfd 11 len 0 debug2: channel 0: read failed channel 0: chan_read_failed for istate 3 debug3: channel 0: will not send data after close debug2: channel 0: read<=0 rfd 11 len 0 debug2: channel 0: read failed channel 0: chan_read_failed for istate 3 debug2: channel 0: rcvd close debug3: channel 0: will not send data after close debug2: channel 0: is dead debug2: channel 0: gc: notify user debug1: session_by_channel: session 0 channel 0 debug1: session_close_by_channel: channel 0 child 0 debug1: session_close: session 0 pid 0 debug2: channel 0: gc: user detached 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 11/11 cfd -1)
debug3: channel 0: close_fds r 11 w 11 e -1 c -1 Connection closed by 192.168.1.80 debug1: do_cleanup debug1: PAM: cleanup debug3: PAM: sshpam_thread_cleanup entering Closing connection to 192.168.1.80 debug1: PAM: cleanup debug3: mm_request_send entering: type 58 debug3: monitor_read: checking request 58 debug3: mm_answer_term: tearing down sessions [root@192.168.1.21 ~]#
Will snip in reply to this.
-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- - - - Jason Pyeron PD Inc. http://www.pdinc.us - - Principal Consultant 10 West 24th Street #100 - - +1 (443) 269-1555 x333 Baltimore, Maryland 21218 - - - -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-
This message is for the designated recipient only and may contain privileged, proprietary, or otherwise private information. If you have received it in error, purge the message from your system and notify the sender immediately. Any other use of the email by you is prohibited.
On Fri, 23 May 2008, Jason Pyeron wrote:
debug3: Normalising mapped IPv4 in IPv6 address debug3: Trying to reverse map address 192.168.1.80.
paused 7 seconds
Here, obviously, is part of the problem. Your name service isn't answering reverse lookups for your LAN addresses -- or it least it isn't answering them in a timely manner. Fixing that, either through DNS or /etc/hosts, will help a bunch.
debug1: do_pam_account: called
pause 7 seconds
debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success)
This delay puzzles me. Are you using LDAP as an authentication backend? If so, reverse-mapping failure may be the issue here, too.
-----Original Message----- From: centos-bounces@centos.org [mailto:centos-bounces@centos.org] On Behalf Of Paul Heinlein Sent: Friday, May 23, 2008 2:17 PM
On Fri, 23 May 2008, Jason Pyeron wrote:
debug3: Normalising mapped IPv4 in IPv6 address debug3: Trying to reverse map address 192.168.1.80.
paused 7 seconds
Here, obviously, is part of the problem. Your name service isn't answering reverse lookups for your LAN addresses -- or it least it isn't answering them in a timely manner. Fixing that, either through DNS or /etc/hosts, will help a bunch.
[root@192.168.1.21 ~]# date && host 192.168.1.80 && date && host host80.1.internal.pdinc.us && date Fri May 23 13:55:52 EDT 2008 80.1.168.192.in-addr.arpa domain name pointer host80.1.internal.pdinc.us. Fri May 23 13:55:52 EDT 2008 host80.1.internal.pdinc.us has address 192.168.1.80 Fri May 23 13:55:52 EDT 2008 [root@192.168.1.21 ~]#
Hmmm, does not take 7 seconds.
debug1: do_pam_account: called
pause 7 seconds
debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success)
This delay puzzles me. Are you using LDAP as an authentication backend? If so, reverse-mapping failure may be the issue here, too.
NIS. But the delay is constant regardless of the user being in the local /etc/passwd or NIS. Further on the local prompt "id user" works just fine.
-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- - - - Jason Pyeron PD Inc. http://www.pdinc.us - - Principal Consultant 10 West 24th Street #100 - - +1 (443) 269-1555 x333 Baltimore, Maryland 21218 - - - -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-
This message is for the designated recipient only and may contain privileged, proprietary, or otherwise private information. If you have received it in error, purge the message from your system and notify the sender immediately. Any other use of the email by you is prohibited.
On Fri, 23 May 2008, Jason Pyeron wrote:
debug3: Normalising mapped IPv4 in IPv6 address debug3: Trying to reverse map address 192.168.1.80.
paused 7 seconds
Here, obviously, is part of the problem. Your name service isn't answering reverse lookups for your LAN addresses -- or it least it isn't answering them in a timely manner. Fixing that, either through DNS or /etc/hosts, will help a bunch.
[root@192.168.1.21 ~]# date && host 192.168.1.80 && date && host host80.1.internal.pdinc.us && date Fri May 23 13:55:52 EDT 2008 80.1.168.192.in-addr.arpa domain name pointer host80.1.internal.pdinc.us. Fri May 23 13:55:52 EDT 2008 host80.1.internal.pdinc.us has address 192.168.1.80 Fri May 23 13:55:52 EDT 2008 [root@192.168.1.21 ~]#
Hmmm, does not take 7 seconds.
User-space utilities like /usr/bin/host don't always provide an accurate reflection of the name services inherited by init- or kernel-launched processes -- especially if the network wasn't (for reasons unknown) fully functional at boot time.
Do you remember if there were any network timeouts when you booted the machine in question?
Are you running nscd?
I'm still inclined to believe that hostname-lookup issues are involved here; an strace with timestamps might provide a better glimpse of the exact system calls that are timing out.
-----Original Message----- From: centos-bounces@centos.org [mailto:centos-bounces@centos.org] On Behalf Of Paul Heinlein Sent: Friday, May 23, 2008 2:35 PM To: CentOS mailing list Subject: RE: [CentOS] how to debug ssh slow connection issues.
On Fri, 23 May 2008, Jason Pyeron wrote:
debug3: Normalising mapped IPv4 in IPv6 address debug3: Trying to reverse map address 192.168.1.80.
paused 7 seconds
Here, obviously, is part of the problem. Your name service isn't answering reverse lookups for your LAN addresses -- or it least it isn't answering them in a timely manner. Fixing that, either through DNS or /etc/hosts, will help a bunch.
[root@192.168.1.21 ~]# date && host 192.168.1.80 && date && host host80.1.internal.pdinc.us && date Fri May 23 13:55:52 EDT 2008 80.1.168.192.in-addr.arpa domain name pointer
host80.1.internal.pdinc.us.
Fri May 23 13:55:52 EDT 2008 host80.1.internal.pdinc.us has address 192.168.1.80 Fri May 23 13:55:52
EDT
2008 [root@192.168.1.21 ~]#
Hmmm, does not take 7 seconds.
User-space utilities like /usr/bin/host don't always provide an accurate reflection of the name services inherited by init- or kernel-launched processes -- especially if the network wasn't (for reasons unknown) fully functional at boot time.
Reboot?
Do you remember if there were any network timeouts when you booted the machine in question?
Oddly, yes there was.
Are you running nscd?
[root@devserver21 ~]# chkconfig --list | grep nscd nscd 0:off 1:off 2:off 3:off 4:off 5:off 6:off
I'm still inclined to believe that hostname-lookup issues are involved here; an strace with timestamps might provide a better glimpse of the exact system calls that are timing out.
Like wise, but with local DNS and local IPs humming perfectly?
-- -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- - - - Jason Pyeron PD Inc. http://www.pdinc.us - - Principal Consultant 10 West 24th Street #100 - - +1 (443) 269-1555 x333 Baltimore, Maryland 21218 - - - -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-
This message is for the designated recipient only and may contain privileged, proprietary, or otherwise private information. If you have received it in error, purge the message from your system and notify the sender immediately. Any other use of the email by you is prohibited.
-----Original Message----- From: centos-bounces@centos.org [mailto:centos-bounces@centos.org] On Behalf Of Jason Pyeron Sent: Friday, May 23, 2008 2:42 PM
-----Original Message----- From: centos-bounces@centos.org [mailto:centos-bounces@centos.org] On Behalf Of Paul Heinlein Sent: Friday, May 23, 2008 2:35 PM
On Fri, 23 May 2008, Jason Pyeron wrote:
debug3: Normalising mapped IPv4 in IPv6 address debug3: Trying to reverse map address 192.168.1.80.
paused 7 seconds
Here, obviously, is part of the problem. Your name service isn't answering reverse lookups for your LAN addresses -- or it least it isn't answering them in a timely manner. Fixing that, either through DNS or /etc/hosts, will help a bunch.
[root@192.168.1.21 ~]# date && host 192.168.1.80 && date && host host80.1.internal.pdinc.us && date Fri May 23 13:55:52 EDT 2008 80.1.168.192.in-addr.arpa domain name pointer
host80.1.internal.pdinc.us.
Fri May 23 13:55:52 EDT 2008 host80.1.internal.pdinc.us has address 192.168.1.80 Fri May 23
13:55:52
EDT
2008 [root@192.168.1.21 ~]#
Hmmm, does not take 7 seconds.
User-space utilities like /usr/bin/host don't always provide an accurate reflection of the name services inherited by init- or kernel-launched processes -- especially if the network wasn't (for reasons unknown) fully functional at boot time.
Reboot?
No effect.
I'm still inclined to believe that hostname-lookup issues are involved here; an strace with timestamps might provide a better glimpse of the exact system calls that are timing out.
Like wise, but with local DNS and local IPs humming perfectly?
Weird:
[root@192.168.1.21 ~]# for i in `ip addr show | perl -ne 'm/inet (.+)// and print $1,"\n";'`; do echo try $i && time ssh $i true && echo; done try 127.0.0.1
real 0m0.093s user 0m0.007s sys 0m0.001s
try public_ip_1_in_/etc/sysconfig/network-scripts/ifcfg-eth0
real 0m5.799s user 0m0.005s sys 0m0.005s
try 192.168.1.21
real 0m28.484s user 0m0.007s sys 0m0.003s
try public_ip_2
real 0m28.552s user 0m0.007s sys 0m0.001s
try public_ip_3
real 0m28.503s user 0m0.007s sys 0m0.003s
try 192.168.1.39
real 0m28.559s user 0m0.006s sys 0m0.003s
try 192.168.1.52
real 0m28.487s user 0m0.006s sys 0m0.003s
try 192.168.1.58
real 0m28.489s user 0m0.008s sys 0m0.002s
-- -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- - - - Jason Pyeron PD Inc. http://www.pdinc.us - - Principal Consultant 10 West 24th Street #100 - - +1 (443) 269-1555 x333 Baltimore, Maryland 21218 - - - -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-
This message is for the designated recipient only and may contain privileged, proprietary, or otherwise private information. If you have received it in error, purge the message from your system and notify the sender immediately. Any other use of the email by you is prohibited.
Try to change this in your /etc/ssh/sshd_config:
If in CentOS 5, change:
AddressFamily any to: AddressFamily inet
If in CentOS 4, change:
ListenAddress :: to: ListenAddress <ip_address_of_your_server_here>
Uncomment those lines if needed.
Change:
GSSAPIAuthentication yes to: GSSAPIAuthentication no
Change:
UseDNS yes to: UseDNS no
Uncomment the last line if applicable.
Then restart your sshd and try to connect again, see if that improved the situation or not. If it did, it's related to DNS.
Keep a backup of your original file and restore it later. Better yet, do the changes on a copied file and then start sshd in the command line in debugging mode with the -f option to specify the new config file.
HTH, Filipe
-----Original Message----- From: centos-bounces@centos.org [mailto:centos-bounces@centos.org] On Behalf Of Filipe Brandenburger Sent: Friday, May 23, 2008 8:55 PM To: CentOS mailing list Subject: Re: [CentOS] how to debug ssh slow connection issues.
Try to change this in your /etc/ssh/sshd_config:
Change:
UseDNS yes to: UseDNS no
Okay that fixed it, but why? I used nslookup and set my server to the same as /etc/resolv.conf. There were no delays, at all all of our class C resolves both ways (and matching) same as out private net.
Where to go next on "properly" fixing this sshd/dns issue?
-- -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- - - - Jason Pyeron PD Inc. http://www.pdinc.us - - Principal Consultant 10 West 24th Street #100 - - +1 (443) 269-1555 x333 Baltimore, Maryland 21218 - - - -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-
This message is for the designated recipient only and may contain privileged, proprietary, or otherwise private information. If you have received it in error, purge the message from your system and notify the sender immediately. Any other use of the email by you is prohibited.
Jason Pyeron wrote:
-----Original Message----- From: centos-bounces@centos.org [mailto:centos-bounces@centos.org] On Behalf Of Filipe Brandenburger Sent: Friday, May 23, 2008 8:55 PM To: CentOS mailing list Subject: Re: [CentOS] how to debug ssh slow connection issues.
Try to change this in your /etc/ssh/sshd_config:
Change:
UseDNS yes to: UseDNS no
Okay that fixed it, but why? I used nslookup and set my server to the same as /etc/resolv.conf. There were no delays, at all all of our class C resolves both ways (and matching) same as out private net.
Where to go next on "properly" fixing this sshd/dns issue?
From the earlier posts, it appears that your DNS server is not properly resolving the REVERSE addresses, i.e. IP address-to-hostname. SSH does a reverse lookup, trying to resolve the IP address to a hostname, unless you set the "UseDNS" option to "no".
Until you fix your DNS server to properly resolve the reverse addresses for your network you will continue to have this issue. Having gone down this road myself, it's not as hard as it sounds. Just having a nameserver resolve your local FORWARD zone won't cut it, you have to have the REVERSE zone set up too.
In my example, I have a local network named "local" (how original!) and use the 192.168.1.0/24 address range. The nameserver I use (Bind 9 on a CentOS box) is configured mostly as a caching nameserver but resolves two local domains, "local" and "1.168.192.in-addr.arpa". All of the name-to-ip entries ("A" records) and aliases ("CNAME" records) are in the "local" zone, all of the ip-to-name entries ("PTR" records) are in the "1.168.192.in-addr.arpa" zone.
If this is mostly gibberish, it might be a good idea to brush up a bit on using the bind nameserver, there are several useful tutorials available on the web, a quick Google search will turn up several. The best reference I can recommend is "DNS and Bind" by Paul Abniz and Cricket Liu, published by O'Reilly. There's a good combination of theory and practice in that book, but it is a daunting read for a newbie.
Just my $.02!
-----Original Message----- From: centos-bounces@centos.org [mailto:centos-bounces@centos.org] On Behalf Of Jay Leafey Sent: Sunday, May 25, 2008 2:17 PM
Jason Pyeron wrote:
-----Original Message----- From: centos-bounces@centos.org [mailto:centos-bounces@centos.org] On Behalf Of Filipe Brandenburger Sent: Friday, May 23, 2008 8:55 PM
Try to change this in your /etc/ssh/sshd_config:
Change:
UseDNS yes to: UseDNS no
Okay that fixed it, but why? I used nslookup and set my server to the
same
as /etc/resolv.conf. There were no delays, at all all of our class C resolves both ways (and matching) same as out private net.
Where to go next on "properly" fixing this sshd/dns issue?
From the earlier posts, it appears that your DNS server is not properly resolving the REVERSE addresses, i.e. IP address-to-hostname. SSH does a reverse lookup, trying to resolve the IP address to a hostname, unless you set the "UseDNS" option to "no".
Agreed, but all of my tests indicate DNS is fine
Until you fix your DNS server to properly resolve the reverse addresses for your network you will continue to have this issue. Having gone down this road myself, it's not as hard as it sounds. Just having a nameserver resolve your local FORWARD zone won't cut it, you have to have the REVERSE zone set up too.
It does the reverse, indicated many posts ago, but has been since snipped out.
In my example, I have a local network named "local" (how original!) and use the 192.168.1.0/24 address range. The nameserver I use (Bind 9 on a CentOS box) is configured mostly as a caching nameserver but resolves two local domains, "local" and "1.168.192.in-addr.arpa". All of the name-to-ip entries ("A" records) and aliases ("CNAME" records) are in the "local" zone, all of the ip-to-name entries ("PTR" records) are in the "1.168.192.in-addr.arpa" zone.
Ditto.
DNS test for 192.168.1.0/24 and known not to exist 192.168.99.99
[root@devserver21 ~]# for i in `seq 0 255`; do host 192.168.1.$i | grep NXDOMAIN; done; host 192.168.99.99 | grep NXDOMAIN Host 99.99.168.192.in-addr.arpa not found: 3(NXDOMAIN) [root@devserver21 ~]# for i in `seq 0 255`; do host 192.168.1.$i; done; host 192.168.99.99
-- -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- - - - Jason Pyeron PD Inc. http://www.pdinc.us - - Principal Consultant 10 West 24th Street #100 - - +1 (443) 269-1555 x333 Baltimore, Maryland 21218 - - - -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-
This message is for the designated recipient only and may contain privileged, proprietary, or otherwise private information. If you have received it in error, purge the message from your system and notify the sender immediately. Any other use of the email by you is prohibited.
-----Original Message----- From: centos-bounces@centos.org [mailto:centos-bounces@centos.org] On Behalf Of Jason Pyeron Sent: Sunday, May 25, 2008 3:27 PM
-----Original Message----- From: centos-bounces@centos.org [mailto:centos-bounces@centos.org] On Behalf Of Jay Leafey Sent: Sunday, May 25, 2008 2:17 PM
From the earlier posts, it appears that your DNS server is not properly resolving the REVERSE addresses, i.e. IP address-to-hostname. SSH does a reverse lookup, trying to resolve the IP address to a hostname, unless you set the "UseDNS" option to "no".
Agreed, but all of my tests indicate DNS is fine
I have also checked the /etc/host* files, all is empty.
-- -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- - - - Jason Pyeron PD Inc. http://www.pdinc.us - - Principal Consultant 10 West 24th Street #100 - - +1 (443) 269-1555 x333 Baltimore, Maryland 21218 - - - -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-
This message is for the designated recipient only and may contain privileged, proprietary, or otherwise private information. If you have received it in error, purge the message from your system and notify the sender immediately. Any other use of the email by you is prohibited.
On Sun, May 25, 2008 at 2:02 PM, Jason Pyeron jpyeron@pdinc.us wrote:
Try to change this in your /etc/ssh/sshd_config:
Change:
UseDNS yes to: UseDNS no
Okay that fixed it, but why? I used nslookup and set my server to the same as /etc/resolv.conf. There were no delays, at all all of our class C resolves both ways (and matching) same as out private net.
Where to go next on "properly" fixing this sshd/dns issue?
Once I had this problem and it was related to IPv6. You may try to see if the other change (ListenAddress :: to ListenAddress <IP>) also fixes the issue without touching DNS. The problem is that sshd tries to resolve IPv6 addresses using AAAA queries and your DNS fails to answer to them, giving it a timeout of 5 seconds for each query (10 seconds in total IIRC).
This is much harder to debug, I've actually found that to be the misbehaviour by using strace on an sshd. You may also try to run "tcpdump udp" on your sshd server, you might see the queries and the timeouts.
In any case, I would say that the "proper" way to fix it is to disable IPv6 if you don't need it and have no use for it. (Or go all the way and configure DNS for it, although it is really tricky right now.) The way to do it is include "alias net-pf-10 off" in /etc/modprobe.conf.
HTH, Filipe
-----Original Message----- From: centos-bounces@centos.org [mailto:centos-bounces@centos.org] On Behalf Of Filipe Brandenburger Sent: Monday, May 26, 2008 12:15 AM To: CentOS mailing list Subject: Re: [CentOS] how to debug ssh slow connection issues.
On Sun, May 25, 2008 at 2:02 PM, Jason Pyeron jpyeron@pdinc.us wrote:
Try to change this in your /etc/ssh/sshd_config:
Change:
UseDNS yes to: UseDNS no
Okay that fixed it, but why? I used nslookup and set my server to the
same
as /etc/resolv.conf. There were no delays, at all all of our class C resolves both ways (and matching) same as out private net.
Where to go next on "properly" fixing this sshd/dns issue?
Once I had this problem and it was related to IPv6. You may try to see if the other change (ListenAddress :: to ListenAddress <IP>) also fixes the issue without touching DNS. The problem is that sshd tries to resolve IPv6 addresses using AAAA queries and your DNS fails to answer to them, giving it a timeout of 5 seconds for each query (10 seconds in total IIRC).
Did that, no net effect.
This is much harder to debug, I've actually found that to be the misbehaviour by using strace on an sshd. You may also try to run "tcpdump udp" on your sshd server, you might see the queries and the timeouts.
So I have a log, but not sure what I am looking at.
debug3: mm_request_receive entering debug3: monitor_read: checking request 6 debug3: mm_answer_pwnamallow debug3: Trying to reverse map address 192.168.1.80. 00:28:03.376914 IP 192.168.1.21.36264 > 192.168.1.10.domain: 38414+ PTR? 80.1.168.192.in-addr.arpa. (43) 00:28:04.041912 IP 192.168.1.10.domain > 192.168.1.21.36264: 38414* 1/1/0 (110)
In any case, I would say that the "proper" way to fix it is to disable IPv6 if you don't need it and have no use for it. (Or go all the way and configure DNS for it, although it is really tricky right now.) The way to do it is include "alias net-pf-10 off" in /etc/modprobe.conf.
Will look into that.
Fixed it, but why????? rpm -e samba system-config-samba samba-common samba-client
-- -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- - - - Jason Pyeron PD Inc. http://www.pdinc.us - - Principal Consultant 10 West 24th Street #100 - - +1 (443) 269-1555 x333 Baltimore, Maryland 21218 - - - -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-
This message is for the designated recipient only and may contain privileged, proprietary, or otherwise private information. If you have received it in error, purge the message from your system and notify the sender immediately. Any other use of the email by you is prohibited.
-
Filipe Brandenburger -
Jason Pyeron -
Jay Leafey -
Paul Heinlein