OpenSSH Login Slowness

[Raymond T Sundland]

   Hi All,
   Forgive me if this is has already been discussed, but I can not find
   any specific mention of the symptoms I am seeing (not the problem
   itself) on any google or mailing list searches.
   Yesterday I built a 5.0 box from CVS and did my normal hardening,
   which include some kernel parameter changes (this is per the
   FreeBSD.org security recommendations page).  In relating to this
   particular email, two of the parameters set are
   'net.inet.udp.blackhole=1' and 'net.inet.udp.log_in_vain=1'.  This, of
   course, creates a "blackhole" for all incoming UDP requests which do
   not have a port open, and logs all such requests respectively.
   After attempting to login to my box via SSH, the session hangs for
   about 1 minute right before it requests authentication:

     % ssh -v smtp01
     OpenSSH_3.4, SSH protocols 1.5/2.0, OpenSSL 0x0090602f
     debug1: Reading configuration data /home/ray/.ssh/config
     debug1: Applying options for smtp01
     debug1: Applying options for *
     debug1: Applying options for *
     debug1: Reading configuration data /etc/ssh/ssh_config
     debug1: Rhosts Authentication disabled, originating port will not
     be trusted.
     debug1: ssh_connect: needpriv 0
     debug1: Connecting to 68.36.18.94 [68.36.18.94] port 22.
     debug1: Connection established.
     debug1: identity file $HOME/.ssh/id_dsa type -1
     debug1: identity file $HOME/.ssh/id_rsa1 type -1
     debug1: Remote protocol version 1.99, remote software version
     OpenSSH_3.5p1 FreeBSD-20021029
     debug1: match: OpenSSH_3.5p1 FreeBSD-20021029 pat OpenSSH*
     Enabling compatibility mode for protocol 2.0
     debug1: Local version string SSH-2.0-OpenSSH_3.4
     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 sent
     debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
     debug1: dh_gen_key: priv key bits set: 119/256
     debug1: bits set: 1566/3191
     debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
     debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
     debug1: Host '68.36.18.94' is known and matches the DSA host key.
     debug1: Found key in /home/ray/.ssh/known_[1]hosts:16
     debug1: bits set: 1525/3191
     debug1: ssh_dss_verify: signature correct
     debug1: kex_derive_keys
     debug1: newkeys: mode 1
     debug1: SSH2_MSG_NEWKEYS sent
     debug1: waiting for SSH2_MSG_NEWKEYS
     debug1: newkeys: mode 0
     debug1: SSH2_MSG_NEWKEYS received
     debug1: done: ssh_kex2.
     debug1: send SSH2_MSG_SERVICE_REQUEST
     debug1: service_accept: ssh-userauth
     debug1: got SSH2_MSG_SERVICE_ACCEPT

   Now during this time, I notice 4 attempts from localhost to connect to
   localhost on port 53 (DNS) [result of 'net.inet.udp.log_in_vain=1']:

     Apr 24 07:56:29 smtp01 kernel: Connection attempt to UDP
     127.0.0.1:53 from 127.0.0.1:49380
     Apr 24 07:56:34 smtp01 kernel: Connection attempt to UDP
     127.0.0.1:53 from 127.0.0.1:49381
     Apr 24 07:56:44 smtp01 kernel: Connection attempt to UDP
     127.0.0.1:53 from 127.0.0.1:49382
     Apr 24 07:57:04 smtp01 kernel: Connection attempt to UDP
     127.0.0.1:53 from 127.0.0.1:49383

   This is definately repeatable.  In fact, everytime I attempt to login
   via SSH, I will get 4 similar messages over a 1 minute period and then
   eventually a successul login.
   If I set 'net.inet.udp.blackhole=0' and try to login again, the same 4
   DNS requests are made to localhost, but because there is no
   blackholing, there is an ICMP port unreachable sent back to localhost
   which allows OpenSSH to know there is no chance of getting an answer.
   (You wouldn't get the ICMP port unreachable with blackholing on).
   Just for shits n giggles, here is a tcpdump of what I'm seeing (with
   'net.inet.udp.blackhole=0'.... remember, no ICMP port unreachables
   with ''net.inet.udp.blackhole=1').

     % tcpdump -i lo0
     tcpdump: listening on lo0
     08:03:06.915924 localhost.49388 > [2]localhost.domain:  15001+ PTR?
     XX.XX.XX.XX.in-addr.arpa. (42)
     08:03:06.915956 localhost > localhost: icmp: localhost udp port
     domain unreachable
     08:03:06.916020 localhost.49389 > [3]localhost.domain:  15001+ PTR?
     XX.XX.XX.XX.in-addr.arpa. (42)
     08:03:06.916038 localhost > localhost: icmp: localhost udp port
     domain unreachable
     08:03:06.916065 localhost.49390 > [4]localhost.domain:  15001+ PTR?
     XX.XX.XX.XX.in-addr.arpa. (42)
     08:03:06.916083 localhost > localhost: icmp: localhost udp port
     domain unreachable
     08:03:06.916111 localhost.49391 > [5]localhost.domain:  15001+ PTR?
     XX.XX.XX.XX.in-addr.arpa. (42)
     08:03:06.916128 localhost > localhost: icmp: localhost udp port
     domain unreachable

   FYI, my real IP has been blacked out for appropriate reasons, but as
   you can see, OpenSSH is making a DNS queries to localhost about my
   real-world IP address (the IP blocked out is a routable IP and not an
   ARIN designated private network IP).
   So, the question [6]is:  Why is OpenSSH requesting DNS calls to
   localhost when there is no mention of '127.0.0.1' in my
   /etc/resolv.conf file.  In fact, in other than hosts and hosts.allow,
   there is no mention of 127.0.0.1 at all under /etc.  BTW, although
   I've said this was a 5.0 box, I have also experienced this on a couple
   4.[78] boxes in the last few months, but I did not have
   'net.inet.udp.log_in_vain=1' set in order to see what was causing the
   problem.
   Thanks for the assistance.
   Ray Sundland
   [7]raymond at SPAMFREEsundland.com

References

   1. hosts:16
   2. localhost.domain:%C2%A0
   3. localhost.domain:%C2%A0
   4. localhost.domain:%C2%A0
   5. localhost.domain:%C2%A0
   6. is:%C2%A0
   7. mailto:raymond at SPAMFREEsundland.com