Very long login by ssh

[Xou]

> Could you also provide the contents of your /etc/profile ? Looks like something in there is causing you all this grief.

Look trace up.

> What about the sizes of /var/adm/wtmps and /var/adm/wtmp?

Look up.

Next is log ssh -vvv user1@SERVER
=============
OpenSSH_5.1p1 Debian-5ubuntu1, OpenSSL 0.9.8g 19 Oct 2007
debug1: Reading configuration data /home/xou/.ssh/config
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug2: ssh_connect: needpriv 0
debug1: Connecting to alm [192.168.1.201] port 22.
debug1: Connection established.
debug1: identity file /home/xou/.ssh/identity type -1
debug3: Not a RSA1 key file /home/xou/.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 /home/xou/.ssh/id_rsa type 1
debug1: Checking blacklist file /usr/share/ssh/blacklist.RSA-2048
debug1: Checking blacklist file /etc/ssh/blacklist.RSA-2048
debug1: identity file /home/xou/.ssh/id_dsa type -1
debug1: Remote protocol version 2.0, remote software version OpenSSH_5.2p1+sftpfilecontrol-v1.3
debug1: match: OpenSSH_5.2p1+sftpfilecontrol-v1.3 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.1p1 Debian-5ubuntu1
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: 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-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
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: 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: 119/256
debug2: bits set: 527/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: check_host_in_hostfile: filename /home/xou/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 26
debug3: check_host_in_hostfile: filename /home/xou/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 27
debug1: Host 'alm' is known and matches the RSA host key.
debug1: Found key in /home/xou/.ssh/known_hosts:26
debug2: bits set: 508/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: /home/xou/.ssh/identity ((nil))
debug2: key: /home/xou/.ssh/id_rsa (0xb8b6ba98)
debug2: key: /home/xou/.ssh/id_dsa ((nil))
debug1: Authentications that can continue: publickey,password,keyboard-interactive
debug3: start over, passed a different list publickey,password,keyboard-interactive
debug3: preferred gssapi-keyex,gssapi-with-mic,gssapi,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: Trying private key: /home/xou/.ssh/identity
debug3: no such identity: /home/xou/.ssh/identity
debug1: Offering public key: /home/xou/.ssh/id_rsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: Server accepts key: pkalg ssh-rsa blen 277
debug2: input_userauth_pk_ok: fp 53:81:f4:01:29:2c:29:32:32:ea:9e:29:e1:6f:19:3e
debug3: sign_and_send_pubkey
debug1: read PEM private key done: type RSA
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.
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 SSH_AGENT_PID
debug3: Ignored env DM_CONTROL
debug3: Ignored env GPG_AGENT_INFO
debug3: Ignored env TERM
debug3: Ignored env DESKTOP_STARTUP_ID
debug3: Ignored env SHELL
debug3: Ignored env XDG_SESSION_COOKIE
debug3: Ignored env XDM_MANAGED
debug3: Ignored env KONSOLE_DBUS_SERVICE
debug3: Ignored env GTK2_RC_FILES
debug3: Ignored env GS_LIB
debug3: Ignored env WINDOWID
debug3: Ignored env KDE_FULL_SESSION
debug3: Ignored env http_proxy
debug3: Ignored env USER
debug3: Ignored env LS_COLORS
debug3: Ignored env SSH_AUTH_SOCK
debug3: Ignored env SESSION_MANAGER
debug3: Ignored env PATH
debug3: Ignored env DESKTOP_SESSION
debug3: Ignored env PWD
debug3: Ignored env KDE_SESSION_UID
debug1: Sending env LANG = ru_RU.UTF-8
debug2: channel 0: request env confirm 0
debug3: Ignored env KONSOLE_DBUS_SESSION
debug3: Ignored env HISTCONTROL
debug3: Ignored env COLORFGBG
debug3: Ignored env HOME
debug3: Ignored env SHLVL
debug3: Ignored env KDE_SESSION_VERSION
debug3: Ignored env LANGUAGE
debug3: Ignored env XCURSOR_THEME
debug3: Ignored env LOGNAME
debug3: Ignored env XDG_DATA_DIRS
debug3: Ignored env DBUS_SESSION_BUS_ADDRESS
debug3: Ignored env LESSOPEN
debug3: Ignored env WINDOWPATH
debug3: Ignored env PROFILEHOME
debug3: Ignored env DISPLAY
debug3: Ignored env QT_PLUGIN_PATH
debug3: Ignored env LESSCLOSE
debug3: Ignored env _
debug3: Ignored env OLDPWD
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
debug2: channel 0: rcvd adjust 2097152
debug2: channel_input_confirm: type 99 id 0
debug2: shell request accepted on channel 0

===========

Wait is after line "debug2: channel 0: open confirm rwindow 0 rmax 32768"

[Dennis Handly]

>> What about the sizes of /var/adm/wtmps and /var/adm/wtmp?

>Look up.

Since you are on 11.31, you may need to check all 6 files:
du -k /var/adm/wtmp* /etc/utmp*

[Mel Burslan]

>> Could you also provide the contents of your /etc/profile ? Looks like something in there is causing you all this grief.

> Look trace up.

I also can not see any trace of /etc/profile anywhere in the thread. Maybe you need to read the postings a little more carefully.

[OldSchool]

Ok, so where/how did the "set -vx" get set. did you type it or stick it in one of the profiles????

it appears to have echoed the .profile. You said it still had a delay, and that the .profile stuff printed in a reasonable time (once it started). that leaves /etc/profile, which still hasn't been posted. you might consider adding a message at the begining and end of that file, or a "set -vx" to that one.

it almost sounds like its trying to do quota checking, but a drive is missing.

[Dennis Handly]

>OldSchool: it almost sounds like its trying to do quota checking, but a drive is missing.

I mentioned that above but I would hope that it prints a progress message saying it is doing that, since it takes some time.

Do we know where in the login process it prints those quota checking messages? Before/after the motd or copyright?
I have:
1) last login info
2) /etc/motd
3) /etc/profile -> You have mail.
4) ~/.profile

[Xou]

Delay was before any messages from server.

Trouble only in sshd from HP:
===
OpenSSH_5.2p1+sftpfilecontrol-v1.3, OpenSSL 0.9.8g 19 Oct 2007
HP-UX Secure Shell-A.05.20.006, HP-UX Secure Shell version
===

Now I use openssh 5.2p1(http://hpux.connect.org.uk/hppd/hpux/Networking/Admin/openssh-5.2p1/). It work good. Thanks to all.

[Xou]

Hi ALL again! :)
I have a new trouble.

When count of ssh users more then 500 many cmnds crashed with "mmap error", for example:
===============================
#glance
/usr/lib/hpux32/dld.so: Cannot map text for library: mmap(0x0, 0x362be0, 0x5, 0x41, 3, 0x0) returns Not enough space.
#xglance
/usr/lib/hpux32/dld.so: Cannot map text for library: mmap(0x0, 0x362be0, 0x5, 0x41, 3, 0x0) returns Not enough space.

#mcedit ~/cmd.log
/usr/lib/hpux32/dld.so: Cannot map text for library: mmap(0x0, 0x2345d0, 0x5, 0x41, 3, 0x0) returns Not enough space.

#/home/user1/somescript.pl
/usr/lib/hpux32/dld.so: Cannot map text for library: mmap(0x0, 0x2f6660, 0x5, 0x41, 3, 0x0) returns Not enough space.
===============================

Kernel limits are not reached:
===============================
# kcusage
Tunable Usage / Setting

filecache_max 3015495680 / 4480000000
maxdsiz 18677760 / 4294963200
maxdsiz_64bit 227475456 / 4294967296
maxfiles_lim 404 / 20480
maxssiz 172032 / 268435456
maxssiz_64bit 1179648 / 1073741824
maxtsiz 35868672 / 134217728
maxtsiz_64bit 28205056 / 34359738368
maxuprc 1005 / 64474
max_thread_proc 128 / 4096
msgmni 2 / 71638
msgtql 0 / 32767
nflocks 20 / 4096
ninode 12300 / 37052
nkthread 27914 / 125382
nproc 6868 / 71638
npty 0 / 4096
nstrpty 815 / 4096
nstrtel 0 / 4096
nswapdev 4 / 32
nswapfs 0 / 32
semmni 154 / 16384
semmns 10697 / 71630
shmmax 19180371968 / 51200000000
shmmni 36 / 9216
shmseg 3 / 8
===============================

And memory usage normal:
===============================
# swapinfo -tam
Mb Mb Mb PCT START/ Mb
TYPE AVAIL USED FREE USED LIMIT RESERVE PRI NAME
dev 16384 0 16384 0% 0 - 1 /dev/vg00/lvol2
dev 131072 19116 111956 15% 0 - 0 /dev/dsk/c9t4d4
dev 131072 19112 111960 15% 0 - 0 /dev/dsk/c9t4d3
dev 208896 0 208896 0% 0 - 1 /dev/vg_local_swap/lv_local_swap0
reserve - 92694 -92694
memory 62209 17613 44596 28%
total 549633 148535 401098 27% - 0 -
===============================

perl in openssh(http://hpux.connect.org.uk/hppd/hpux/Networking/Admin/openssh-5.2p1/) run-time dependencies list is default hpux 11.31 bundle, but may problem be in it???
===============================
swlist |grep -i perl
perl D.5.8.8.F Perl Programming Language
===============================

[Dennis Handly]

>When count of ssh users more then 500 many cmnds crashed with "mmap error",
>dld.so: Cannot map text for library : mmap(0x0, 0x362be0, 0x5, 0x41, 3, 0x0) returns Not enough space.

You are out of shared memory space or it is too fragmented.
What does "ipcs -ma" show?

You may need a newer linker/dld patch?

If this doesn't solve it, you'll have to contact the Response Center to get a tool that can print details on your shared memory allocations.

Or port your ssh to 64 bit.

[Dennis Handly]

>ME: You are out of shared memory space or it is too fragmented.

Here is a thread where they are talking about shared memory space for mmap and the shminfo tool:
http://forums.itrc.hp.com/service/forums/questionanswer.do?threadId=1364505

[Wiktor Cieślak]

Hi Xou,
What Steve Post said may be right but according to /var/adm/wtmps file. Check

ll /var/adm/wtmps

I had same problem on some servers, on one of them wtmps file was 1,8GB big and login took over 1 min. After I have zeroing the wtmps file, login takes ~2 sec.
You can use script below to archive and clear wtmps file:

/usr/sbin/acct/fwtmp < /var/adm/wtmps > $SOME_DIR/wtmp_`date +%Y%m%d`.txt

cat /dev/null > /var/adm/wtmps

Pozdrawiam