[lug] SSHD connection delay
Dean Johnson
deanjohnson3 at gmail.com
Tue Jul 26 12:15:29 MDT 2011
One server (172.22.30.8) on a recently reconfigured network has a
consistent 30 second delay setting up an ssh connection.
It had been instant, like all others, before the network update. The
server is a Fedora 8 machine running openssh-server.i386 4.7p1-2.fc8.
The delay occurs after entering the PWD.
I have temporarily addressed the issue by setting the "UseDNS no"
option in /etc/ssh/sshd_config. I would like to use the default
configuration after I have learned what is really not working and
fixed it...
(Please do not throw rotten fruit...) The DNS servers is Win2003 R2.
These machines are all inside our firewall.
On both clients and the server, I have tested resolving names and ipaddresses:
Machines:
server 5ki-is 172.22.30.8 (Fedora 8)
client djohnson 172.20.1.131 (Win7) and three Linux virtual machines
client jane 172 20.1.144 (SL7)
[root at 5ki-is ~]# dig djohnson @172.20.1.21
; <<>> DiG 9.5.0a6 <<>> djohnson @172.20.1.21
;; global options: printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: SERVFAIL, id: 41736
;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0
;; QUESTION SECTION:
;djohnson. IN A
;; Query time: 0 msec
;; SERVER: 172.20.1.21#53(172.20.1.21)
;; WHEN: Tue Jul 26 11:22:21 2011
;; MSG SIZE rcvd: 26
[root at 5ki-is ~]# dig djohnson.azteknetworks.net @172.20.1.21
; <<>> DiG 9.5.0a6 <<>> djohnson.azteknetworks.net @172.20.1.21
;; global options: printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 878
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0
;; QUESTION SECTION:
;djohnson.azteknetworks.net. IN A
;; ANSWER SECTION:
djohnson.azteknetworks.net. 900 IN A 172.20.1.131
;; Query time: 8 msec
;; SERVER: 172.20.1.21#53(172.20.1.21)
;; WHEN: Tue Jul 26 11:23:13 2011
;; MSG SIZE rcvd: 60
[root at 5ki-is ~]# host djohnson
djohnson.azteknetworks.net has address 172.20.1.131
[root at 5ki-is ~]# nslookup djohnson
Server: 172.20.1.21
Address: 172.20.1.21#53
Name: djohnson.azteknetworks.net
Address: 172.20.1.131
[root at 5ki-is ~]# dig -x 172.20.1.131 @172.20.1.21
; <<>> DiG 9.5.0a6 <<>> -x 172.20.1.131 @172.20.1.21
;; global options: printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 65355
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0
;; QUESTION SECTION:
;131.1.20.172.in-addr.arpa. IN PTR
;; ANSWER SECTION:
131.1.20.172.in-addr.arpa. 900 IN PTR djohnson.azteknetworks.net.
;; Query time: 1 msec
;; SERVER: 172.20.1.21#53(172.20.1.21)
;; WHEN: Tue Jul 26 11:24:33 2011
;; MSG SIZE rcvd: 83
[root at 5ki-is ~]# host 172.20.1.131
131.1.20.172.in-addr.arpa domain name pointer djohnson.azteknetworks.net.
[root at 5ki-is ~]# nslookup 172.20.1.131
Server: 172.20.1.21
Address: 172.20.1.21#53
131.1.20.172.in-addr.arpa name = djohnson.azteknetworks.net.
/etc/resolv.conf:
[root at 5ki-is ~]# cat /etc/resolv.conf
search azteknetworks.net test.azteknetworks.net
nameserver 172.20.1.21
nameserver 172.20.1.22
It looks like reverse lookups are OK.
It seems that there is a glitch in forward lookup of aliases, compared to FQDN.
The /etc/pam.d/sshd file is identical between two similar servers, one
with and one without the delay:
#%PAM-1.0
auth include system-auth
account required pam_nologin.so
account include system-auth
password include system-auth
session optional pam_keyinit.so force revoke
session include system-auth
session required pam_loginuid.so
/etc/sshd_config:
# $OpenBSD: sshd_config,v 1.75 2007/03/19 01:01:29 djm Exp $
# This is the sshd server system-wide configuration file. See
# sshd_config(5) for more information.
# This sshd was compiled with PATH=/usr/local/bin:/bin:/usr/bin
# The strategy used for options in the default sshd_config shipped with
# OpenSSH is to specify options with their default value where
# possible, but leave them commented. Uncommented options change a
# default value.
#Port 22
#AddressFamily any
#ListenAddress 0.0.0.0
#ListenAddress ::
# Disable legacy (protocol version 1) support in the server for new
# installations. In future the default will change to require explicit
# activation of protocol 1
Protocol 2
# HostKey for protocol version 1
#HostKey /etc/ssh/ssh_host_key
# HostKeys for protocol version 2
#HostKey /etc/ssh/ssh_host_rsa_key
#HostKey /etc/ssh/ssh_host_dsa_key
# Lifetime and size of ephemeral version 1 server key
#KeyRegenerationInterval 1h
#ServerKeyBits 768
# Logging
# obsoletes QuietMode and FascistLogging
#SyslogFacility AUTH
SyslogFacility AUTHPRIV
LogLevel DEBUG
# Authentication:
#LoginGraceTime 2m
#PermitRootLogin yes
#StrictModes yes
#MaxAuthTries 6
#RSAAuthentication yes
#PubkeyAuthentication yes
#AuthorizedKeysFile .ssh/authorized_keys
# For this to work you will also need host keys in /etc/ssh/ssh_known_hosts
#RhostsRSAAuthentication no
# similar for protocol version 2
#HostbasedAuthentication no
# Change to yes if you don't trust ~/.ssh/known_hosts for
# RhostsRSAAuthentication and HostbasedAuthentication
#IgnoreUserKnownHosts no
# Don't read the user's ~/.rhosts and ~/.shosts files
#IgnoreRhosts yes
# To disable tunneled clear text passwords, change to no here!
#PasswordAuthentication yes
#PermitEmptyPasswords no
PasswordAuthentication yes
# Change to no to disable s/key passwords
#ChallengeResponseAuthentication yes
ChallengeResponseAuthentication no
# Kerberos options
#KerberosAuthentication no
#KerberosOrLocalPasswd yes
#KerberosTicketCleanup yes
#KerberosGetAFSToken no
# GSSAPI options
#GSSAPIAuthentication no
GSSAPIAuthentication yes
#GSSAPICleanupCredentials yes
GSSAPICleanupCredentials yes
# Set this to 'yes' to enable PAM authentication, account processing,
# and session processing. If this is enabled, PAM authentication will
# be allowed through the ChallengeResponseAuthentication and
# PasswordAuthentication. Depending on your PAM configuration,
# PAM authentication via ChallengeResponseAuthentication may bypass
# the setting of "PermitRootLogin without-password".
# If you just want the PAM account and session checks to run without
# PAM authentication, then enable this but set PasswordAuthentication
# and ChallengeResponseAuthentication to 'no'.
#UsePAM no
UsePAM yes
# Accept locale-related environment variables
AcceptEnv LANG LC_CTYPE LC_NUMERIC LC_TIME LC_COLLATE LC_MONETARY LC_MESSAGES
AcceptEnv LC_PAPER LC_NAME LC_ADDRESS LC_TELEPHONE LC_MEASUREMENT
AcceptEnv LC_IDENTIFICATION LC_ALL
#AllowTcpForwarding yes
#GatewayPorts no
#X11Forwarding no
X11Forwarding yes
#X11DisplayOffset 10
#X11UseLocalhost yes
#PrintMotd yes
#PrintLastLog yes
#TCPKeepAlive yes
#UseLogin no
#UsePrivilegeSeparation yes
#PermitUserEnvironment no
#Compression delayed
#ClientAliveInterval 0
#ClientAliveCountMax 3
#ShowPatchLevel no
#UseDNS yes
#PidFile /var/run/sshd.pid
#MaxStartups 10
#PermitTunnel no
# no default banner path
#Banner /some/path
# override default of no subsystems
Subsystem sftp /usr/libexec/openssh/sftp-server
# Example of overriding settings on a per-user basis
#Match User anoncvs
# X11Forwarding no
# AllowTcpForwarding no
# ForceCommand cvs server
One odd thing I haven't yet been able to eliminate in the network
configuration is an ICMP Redirect message when pinging from another
subnet.
Network description:
We have HP Procurve "layer 3 routing" capable switches which I am
using to host three or four subnets each. They are connected via a
trunk, the second switch giving me connection to the test subnets
(172.22.0.0/16).
Example of glitch with the routing going from the main network to the
test networks:
[dmj at jane ~]$ ping 5ki-is
PING 5ki-is.test.azteknetworks.net (172.22.30.8) 56(84) bytes of data.
>From aztekhp5406zl.azteknetworks.net (172.20.1.1): icmp_seq=1 Redirect
Host(New nexthop: testlab2910.azteknetworks.net (172.20.1.3))
64 bytes from 5ki-is.test.azteknetworks.net (172.22.30.8): icmp_seq=1
ttl=63 time=3.79 ms
64 bytes from 5ki-is.test.azteknetworks.net (172.22.30.8): icmp_seq=2
ttl=63 time=0.156 ms
64 bytes from 5ki-is.test.azteknetworks.net (172.22.30.8): icmp_seq=3
ttl=63 time=0.140 ms
64 bytes from 5ki-is.test.azteknetworks.net (172.22.30.8): icmp_seq=4
ttl=63 time=0.131 ms
64 bytes from 5ki-is.test.azteknetworks.net (172.22.30.8): icmp_seq=5
ttl=63 time=0.128 ms
^C
--- 5ki-is.test.azteknetworks.net ping statistics ---
5 packets transmitted, 5 received, 0% packet loss, time 4134ms
rtt min/avg/max/mdev = 0.128/0.869/3.792/1.461 ms
Here is the server output of a sample SSH connection:
Jul 22 10:56:16 localhost sshd[32375]: debug1: attempt 0 failures 0
Jul 22 10:56:16 localhost sshd[32374]: debug1: PAM: initializing for "dmj"
Jul 22 10:56:16 localhost sshd[32374]: debug1: PAM: setting PAM_RHOST
to "djohnson.azteknetworks.net"
Jul 22 10:56:16 localhost sshd[32374]: debug1: PAM: setting PAM_TTY to "ssh"
Jul 22 10:56:28 localhost sshd[32375]: debug1: userauth-request for
user dmj service ssh-connection method password
Jul 22 10:56:28 localhost sshd[32375]: debug1: attempt 1 failures 1
Jul 22 10:56:33 localhost sshd[32374]: debug1: PAM: password
authentication accepted for dmj
Jul 22 10:56:33 localhost sshd[32374]: debug1: do_pam_account: called
Jul 22 10:56:38 localhost sshd[32374]: Accepted password for dmj from
172.20.1.131 port 13856 ssh2
Jul 22 10:56:38 localhost sshd[32374]: debug1: monitor_child_preauth:
dmj has been authenticated by privileged process
Jul 22 10:56:38 localhost sshd[32374]: debug1: temporarily_use_uid:
6133/100 (e=0/0)
Jul 22 10:56:38 localhost sshd[32374]: debug1: ssh_gssapi_storecreds:
Not a GSSAPI mechanism
Jul 22 10:56:38 localhost sshd[32374]: debug1: restore_uid: 0/0
Jul 22 10:56:38 localhost sshd[32374]: debug1: SELinux support disabled
Jul 22 10:56:38 localhost sshd[32374]: debug1: PAM: establishing credentials
Jul 22 10:56:43 localhost sshd[32374]: pam_unix(sshd:session): session
opened for user dmj by (uid=0)
Jul 22 10:56:48 localhost sshd[32376]: debug1: PAM: reinitializing credentials
Jul 22 10:56:53 localhost sshd[32376]: debug1: permanently_set_uid: 6133/100
Jul 22 10:56:53 localhost sshd[32376]: debug1: Entering interactive
session for SSH2.
Jul 22 10:56:53 localhost sshd[32376]: debug1: server_init_dispatch_20
Jul 22 10:56:53 localhost sshd[32376]: debug1:
server_input_channel_open: ctype session rchan 256 win 16384 max 16384
Jul 22 10:56:53 localhost sshd[32376]: debug1: input_session_request
Jul 22 10:56:53 localhost sshd[32376]: debug1: channel 0: new [server-session]
Jul 22 10:56:53 localhost sshd[32376]: debug1: session_new: init
Jul 22 10:56:53 localhost sshd[32376]: debug1: session_new: session 0
Jul 22 10:56:53 localhost sshd[32376]: debug1: session_open: channel 0
Jul 22 10:56:53 localhost sshd[32376]: debug1: session_open: session
0: link with channel 0
Jul 22 10:56:53 localhost sshd[32376]: debug1:
server_input_channel_open: confirm session
Jul 22 10:56:53 localhost sshd[32376]: debug1:
server_input_channel_req: channel 0 request pty-req reply 1
Jul 22 10:56:53 localhost sshd[32376]: debug1: session_by_channel:
session 0 channel 0
Jul 22 10:56:53 localhost sshd[32376]: debug1:
session_input_channel_req: session 0 req pty-req
Jul 22 10:56:53 localhost sshd[32376]: debug1: Allocating pty.
Jul 22 10:56:53 localhost sshd[32374]: debug1: session_new: init
Jul 22 10:56:53 localhost sshd[32374]: debug1: session_new: session 0
Jul 22 10:56:58 localhost sshd[32376]: debug1: session_pty_req:
session 0 alloc /dev/pts/4
Jul 22 10:56:58 localhost sshd[32376]: debug1:
server_input_channel_req: channel 0 request shell reply 1
Jul 22 10:56:58 localhost sshd[32376]: debug1: session_by_channel:
session 0 channel 0
Jul 22 10:56:58 localhost sshd[32376]: debug1:
session_input_channel_req: session 0 req shell
Jul 22 10:56:58 localhost sshd[32377]: debug1: Setting controlling tty
using TIOCSCTTY.
Thanks for any input you can offer!
Dean
More information about the LUG
mailing list