[lug] SSHD connection delay

[Anthony Foiani]

Dean Johnson <deanjohnson3 at gmail.com> writes:

> 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.

Could you explain that a bit better?  After entering the working
directory?  Or after entering the password?

30s is traditionally a DNS issue, as you pursued.  Did the network
reconfig happen to turn on/off IPv6?  (Dunno if FC8 runs into that
problem or not...)  What actually got changed in the network reconfig?

Is there any automounting going on?

Does the output from "ssh -v" (or "-d", whichever it is) show any
obvious lag?  Likewise for sshd?  Ah, I see you included some below...

> On both clients and the server, I have tested resolving names and
> ipaddresses:

They seem to have come back nearly instantly; is that the experience
at the command line as well?

Are you sure that the FC8 system has the correct /etc/resolv.conf
entries, and that /etc/nsswitch.conf (if FC8 uses it?) is configured
correctly?

Do you have any stale bind / recursor config files around?

Have you tried running tcpdump on packets to/from DNS ports (53) to
see if anythng fishy is going on?

> 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)

Is the routing set up sanely, or is there possibly some discovery junk
going on (PMTU / ECN)?  Or are you just on a honkin' big subnet (what
is that, a /12?)

> 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

12s for that?  Or was that a pause for password entry?

> 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: PAM: establishing credentials
> Jul 22 10:56:43 localhost sshd[32374]: pam_unix(sshd:session): session
> opened for user dmj by (uid=0)

5s for each of those?  What class CPU is this on, and is there any NFS
mounting going on?

> 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

And another 5s pause.

Let us know if you figure it out!

t.