Login delay after entering id (40 secs) same after entering pw

Hi all,

I have just installed Solaris 10 on an old Fujitsu Primepower 650 which has been wiped clean. I haven't installed anything apart from the OS yet, so the machine is 99% idle.

I get long delays when logging in, first after entering the id then another long delay after entering a valid password. The delay is always exactly 40 seconds. (Unless I enter an invalid password in which case I get the "access denied" message back straight away.)

I am using Putty to connect to the box over ssh port 22. I don't get the problem when logging in to the console, so I guess it's an ssh issue. I haven't changed anything in sshd_config though, maybe this needs configuring but surely should work OK out of the box?

Any clues much appreciated.

Jon

perhaps its "reverse DNS not working correctly":
Getting Rid of SSH or SFTP Delay Brit Gardner

if its always exact 40sec, it might be some kind of security measure.

Hmmm no didn't work, but thanks anyway!

have you restarted the sshd on your machine the "solaris" way? because this sudo /etc/init.d/ssh restart won't do it...

this one SHOULD work on solaris:

# svcadm restart network/ssh 

Thanks Duke, I had assumed that sshd re-spawned and re-read the config file for every new connection, but apparently not.

And adding in the UseDNS no directive appears to scotch ssh altogether until reboot.

Still have an 80 sec delay :wall:

In your home directory:

touch .hushlogin

Try again. If the delay disappeared, quota checks, probably on NFS file systems, are the cause of your delay.

Seems it's not quota checks, but thanks anyway achenle.

Following is ssh -vvv log from a remote login to the box having the problem. Weirdest thing is this problem is occuring on the global zone, but not on a non-global zone I've set up on this box.

schplps01l:~ # ssh -vvv schpogcor01s
OpenSSH_5.1p1, OpenSSL 0.9.8h 28 May 2008
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug2: ssh_connect: needpriv 0
debug1: Connecting to schpogcor01s [xxx.xxx.xxx.xxx] port 22.
debug1: Connection established.
debug1: permanently_set_uid: 0/0
debug3: Not a RSA1 key file /root/.ssh/id_rsa.
debug2: key_type_from_name: unknown key type '-----BEGIN'
debug3: key_read: missing keytype
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug2: key_type_from_name: unknown key type '-----END'
debug3: key_read: missing keytype
debug1: identity file /root/.ssh/id_rsa type 1
debug3: Not a RSA1 key file /root/.ssh/id_dsa.
debug2: key_type_from_name: unknown key type '-----BEGIN'
debug3: key_read: missing keytype
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug2: key_type_from_name: unknown key type '-----END'
debug3: key_read: missing keytype
debug1: identity file /root/.ssh/id_dsa type 2
debug1: Remote protocol version 2.0, remote software version Sun_SSH_1.1.4
debug1: no match: Sun_SSH_1.1.4
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.1
debug2: fd 3 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-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,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
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: gss-group1-sha1-toWM5Slw5Ew8Mqkay+al2g==,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc,aes192-ctr,aes192-cbc,aes256-ctr,aes256-cbc
debug2: kex_parse_kexinit: aes128-ctr,aes128-cbc,arcfour,3des-cbc,blowfish-cbc,aes192-ctr,aes192-cbc,aes256-ctr,aes256-cbc
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: de-LU,en-GB,en-IE,fr,fr-BE,fr-FR,fr-LU,nl-BE,nl,nl-NL,i-default
debug2: kex_parse_kexinit: de-LU,en-GB,en-IE,fr,fr-BE,fr-FR,fr-LU,nl-BE,nl,nl-NL,i-default
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: mac_setup: found hmac-md5
debug1: kex: server->client aes128-cbc hmac-md5 none
debug2: mac_setup: found hmac-md5
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
debug2: dh_gen_key: priv key bits set: 129/256
debug2: bits set: 541/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: check_host_in_hostfile: filename /root/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 25
debug3: check_host_in_hostfile: filename /root/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 25
debug1: Host 'schpogcor01s' is known and matches the RSA host key.
debug1: Found key in /root/.ssh/known_hosts:25
debug2: bits set: 503/1024
debug1: ssh_rsa_verify: signature correct
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: SSH2_MSG_SERVICE_REQUEST sent
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: /root/.ssh/id_rsa (0xb781a328)
debug2: key: /root/.ssh/id_dsa (0xb781a298)
debug1: Authentications that can continue: publickey,password,keyboard-interactive
debug3: start over, passed a different list publickey,password,keyboard-interactive
debug3: preferred publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Offering public key: /root/.ssh/id_rsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: Authentications that can continue: publickey,password,keyboard-interactive
debug1: Offering public key: /root/.ssh/id_dsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: Server accepts key: pkalg ssh-dss blen 434
debug2: input_userauth_pk_ok: fp 0c:fd:d1:ce:dd:45:df:20:0f:9f:f9:2d:27:b8:5d:6a
debug3: sign_and_send_pubkey
debug1: read PEM private key done: type DSA

40 sec delay

debug1: Authentication succeeded (publickey).
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug1: Requesting no-more-sessions@openssh.com
debug1: Entering interactive session.

40 sec delay

debug2: callback start
debug2: client_session2_setup: id 0
debug2: channel 0: request pty-req confirm 1
debug3: tty_make_modes: ospeed 38400
debug3: tty_make_modes: ispeed 38400
debug1: Sending environment.
debug3: Ignored env LESSKEY
debug3: Ignored env NNTPSERVER
debug3: Ignored env INFODIR
debug3: Ignored env MANPATH
debug3: Ignored env ORA_CRS_HOME
debug3: Ignored env HOSTNAME
debug3: Ignored env XKEYSYMDB
debug3: Ignored env HOST
debug3: Ignored env SHELL
debug3: Ignored env TERM
debug3: Ignored env PROFILEREAD
debug3: Ignored env HISTSIZE
debug3: Ignored env MORE
debug3: Ignored env ORA_ASM_HOME
debug3: Ignored env http_proxy
debug3: Ignored env JRE_HOME
debug3: Ignored env USER
debug3: Ignored env LS_COLORS
debug3: Ignored env ORACLE_SID
debug3: Ignored env XNLSPATH
debug3: Ignored env ENV
debug3: Ignored env ORACLE_BASE
debug3: Ignored env HOSTTYPE
debug3: Ignored env ftp_proxy
debug3: Ignored env FROM_HEADER
debug3: Ignored env PAGER
debug3: Ignored env CSHEDIT
debug3: Ignored env XDG_CONFIG_DIRS
debug3: Ignored env MINICOM
debug3: Ignored env MAIL
debug3: Ignored env PATH
debug3: Ignored env CPU
debug3: Ignored env JAVA_BINDIR
debug3: Ignored env INPUTRC
debug3: Ignored env PWD
debug3: Ignored env JAVA_HOME
debug1: Sending env LANG = POSIX
debug2: channel 0: request env confirm 0
debug3: Ignored env PYTHONSTARTUP
debug3: Ignored env https_proxy
debug3: Ignored env QT_SYSTEM_DIR
debug3: Ignored env SHLVL
debug3: Ignored env HOME
debug3: Ignored env LESS_ADVANCED_PREPROCESSOR
debug3: Ignored env OSTYPE
debug3: Ignored env LS_OPTIONS
debug3: Ignored env no_proxy
debug3: Ignored env XCURSOR_THEME
debug3: Ignored env WINDOWMANAGER
debug3: Ignored env LESS
debug3: Ignored env MACHTYPE
debug3: Ignored env LOGNAME
debug3: Ignored env CVS_RSH
debug3: Ignored env XDG_DATA_DIRS
debug1: Sending env LC_CTYPE = en_GB.UTF-8
debug2: channel 0: request env confirm 0
debug3: Ignored env LESSOPEN
debug3: Ignored env INFOPATH
debug3: Ignored env DISPLAY
debug3: Ignored env ORACLE_HOME
debug3: Ignored env XAUTHLOCALHOSTNAME
debug3: Ignored env LESSCLOSE
debug3: Ignored env G_BROKEN_FILENAMES
debug3: Ignored env JAVA_ROOT
debug3: Ignored env COLORTERM
debug3: Ignored env XAUTHORITY
debug3: Ignored env _
debug2: channel 0: request shell confirm 1
debug2: fd 3 setting TCP_NODELAY
debug2: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel_input_confirm: type 99 id 0
debug2: PTY allocation request accepted on channel 0
debug1: Remote: Channel 0 set: LANG=POSIX
debug1: Remote: Channel 0 set: LC_CTYPE=en_GB.UTF-8
debug2: channel 0: rcvd adjust 131072
debug2: channel_input_confirm: type 99 id 0
debug2: shell request accepted on channel 0
Last login: Thu Jan 19 15:56:40 2012 from 172.30.174.11
Oracle Corporation      SunOS 5.10      Generic Patch   January 2005
#

Well, if you have root access on the server you can truss the running sshd process and see what's hanging:

truss -f -d -vall -o /output/file/name -p PID

Where PID is the process id of the sshd process that's actually listening on port 22. It'll probably be the only one with a parent PID of 1 in the global zone. Just make sure the output file name is to a secure path because the file it generates will capture everything.

That will show you where the hang is happening. But you need root access and you'll need to dig through the output file to find it. If you can, tail the file while you're logging in to see the timeout as it rolls by and see what to look for.

Just a guess, but is your remote host listed in the host file in the local zone, but not in the global zone? Or are there differences in the nameservers used for DNS lookups? You can try doing an nslookup on your remote host's IP address in both zones.

OK so, for posterity, the solution was:

• no /etc/hostname.xxx file - when the machine was first installed it could not get on to the network due to switch/router config, so this file was not created. This meant that after reboot the network was not up and required setting up again
• incorrectly configured hosts file - the host name was against the local loopback address, so the network service could not match the network card to the IP address.

This meant that when UseDNS=no was set in /etc/ssh/sshd_config it just hung ssh. Once the above issues were resolved, adding UseDNS=no then did sort out the long hangs since we do not have DNS ports and servers running on our back-end DB server subnets.

I did try trussing the process as suggested, achenle, and I saw the process hanging on door_calls, but this didn't tell me much in this case, as it was indeed reverse DNS lookups which were causing the problem.

Moral?: re-check your basic config files and get your colleagues to check them if they look OK to you! Thanks all for your help and suggestions.