[solved] sshd:PAM: authentication thread exited unexpectedly

Message

aceFruchtsaft · Post by **aceFruchtsaft** » Sun Oct 01, 2006 4:54 pm

For days I've been trying to fix my OpenSSH server which is running on my local file server, so I'm really desperate right now.
I use sshd -> PAM -> LDAP for authentication, but other services which authenticate directly against OpenLDAP (like Samba) oder indirectly via PAM (like apache, postfix, cyrus-imapd, etc...) all work.

With /usr/sbin/sshd -dd i get this debugging output:

Code: Select all

debug2: load_server_config: filename /etc/ssh/sshd_config
debug2: load_server_config: done config len = 228
debug2: parse_server_config: config /etc/ssh/sshd_config len 228
debug1: sshd version OpenSSH_4.3p2
debug1: read PEM private key done: type RSA
debug1: private host key: #0 type 1 RSA
debug1: read PEM private key done: type DSA
debug1: private host key: #1 type 2 DSA
debug1: rexec_argv[0]='/usr/sbin/sshd'
debug1: rexec_argv[1]='-dd'
debug2: fd 3 setting O_NONBLOCK
debug1: Bind to port 22 on 0.0.0.0.
Server listening on 0.0.0.0 port 22.
socket: Address family not supported by protocol
debug1: Server will not fork when running in debugging mode.
debug1: rexec start in 4 out 4 newsock 4 pipe -1 sock 7
debug1: inetd sockets after dupping: 3, 3
Connection from 10.88.0.3 port 54122
debug1: Client protocol version 2.0; client software version OpenSSH_4.3
debug1: match: OpenSSH_4.3 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_4.3
debug2: fd 3 setting O_NONBLOCK
debug1: permanently_set_uid: 22/22
debug1: list_hostkey_types: ssh-rsa,ssh-dss
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: 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,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com
debug2: kex_parse_kexinit: none,zlib@openssh.com
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-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,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,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_init: found hmac-md5
debug1: kex: client->server aes128-cbc hmac-md5 none
debug2: mac_init: found hmac-md5
debug1: kex: server->client aes128-cbc hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received
debug2: Network child is on pid 8589
debug2: monitor_read: 0 used once, disabling now
debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
debug2: dh_gen_key: priv key bits set: 123/256
debug2: bits set: 511/1024
debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
debug2: bits set: 510/1024
debug2: monitor_read: 5 used once, disabling now
debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
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: KEX done
debug1: userauth-request for user root service ssh-connection method none
debug1: attempt 0 failures 0
debug2: monitor_read: 7 used once, disabling now
debug2: input_userauth_request: setting up authctxt for root
debug2: input_userauth_request: try method none
Failed none for root from 10.88.0.3 port 54122 ssh2
debug1: userauth-request for user root service ssh-connection method keyboard-interactive
debug1: attempt 1 failures 1
debug2: input_userauth_request: try method keyboard-interactive
debug1: keyboard-interactive devs 
debug1: auth2_challenge: user=root devs=
debug1: kbdint_alloc: devices 'pam'
debug2: auth2_challenge_start: devices pam
debug2: kbdint_next_device: devices <empty>
debug1: auth2_challenge_start: trying authentication method 'pam'
debug1: PAM: initializing for "root"
debug1: PAM: setting PAM_RHOST to "foobar"
debug1: PAM: setting PAM_TTY to "ssh"
debug2: monitor_read: 46 used once, disabling now
debug2: monitor_read: 3 used once, disabling now
debug2: monitor_read: 4 used once, disabling now
Postponed keyboard-interactive for root from 10.88.0.3 port 54122 ssh2
debug2: PAM: sshpam_respond entering, 1 responses
debug1: do_pam_account: called
PAM: authentication thread exited unexpectedly
debug1: do_cleanup
debug1: PAM: cleanup
debug1: do_cleanup
debug1: PAM: cleanup

As you see something's wrong with PAM authentication.

ssh -vv foobar gives:

Code: Select all

OpenSSH_4.3p2, OpenSSL 0.9.8d 28 Sep 2006
debug1: Reading configuration data /etc/ssh/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to trillian [10.88.0.3] port 22.
debug1: Connection established.
debug1: permanently_set_uid: 0/0
debug1: identity file /root/.ssh/identity type -1
debug1: identity file /root/.ssh/id_rsa type -1
debug1: identity file /root/.ssh/id_dsa type -1
debug1: Remote protocol version 2.0, remote software version OpenSSH_4.3
debug1: match: OpenSSH_4.3 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_4.3
debug2: fd 3 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: 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,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,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-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,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib@openssh.com
debug2: kex_parse_kexinit: none,zlib@openssh.com
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug2: mac_init: found hmac-md5
debug1: kex: server->client aes128-cbc hmac-md5 none
debug2: mac_init: 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: 145/256
debug2: bits set: 510/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug1: Host 'trillian' is known and matches the RSA host key.
debug1: Found key in /root/.ssh/known_hosts:1
debug2: bits set: 511/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/identity ((nil))
debug2: key: /root/.ssh/id_rsa ((nil))
debug2: key: /root/.ssh/id_dsa ((nil))
debug1: Authentications that can continue: publickey,keyboard-interactive
debug1: Next authentication method: publickey
debug1: Trying private key: /root/.ssh/identity
debug1: Trying private key: /root/.ssh/id_rsa
debug1: Trying private key: /root/.ssh/id_dsa
debug2: we did not send a packet, disable method
debug1: Next authentication method: keyboard-interactive
debug2: userauth_kbdint
debug2: we sent a keyboard-interactive packet, wait for reply
debug2: input_userauth_info_req
debug2: input_userauth_info_req: num_prompts 1
Connection closed by 10.88.0.3

My sshd_config (basically unchanged, I stripped all comments):

Code: Select all

Protocol 2
PasswordAuthentication no
UsePAM yes
 
Subsystem	sftp	/usr/lib64/misc/sftp-server

My LDAP log (with almost maximum verbosity):

Code: Select all

Oct  1 13:58:35 trillian slapd[7953]: daemon: activity on 1 descriptors
Oct  1 13:58:35 trillian slapd[7953]: daemon: new connection on 11
Oct  1 13:58:35 trillian slapd[7953]: conn=5 fd=11 ACCEPT from IP=10.88.0.3:41259 (IP=0.0.0.0:389)
Oct  1 13:58:35 trillian slapd[7953]: daemon: added 11r
Oct  1 13:58:35 trillian slapd[7953]: daemon: activity on:
Oct  1 13:58:35 trillian slapd[7953]: 
Oct  1 13:58:35 trillian slapd[7953]: daemon: select: listen=6 active_threads=0 tvp=NULL
Oct  1 13:58:35 trillian slapd[7953]: daemon: select: listen=7 active_threads=0 tvp=NULL
Oct  1 13:58:35 trillian slapd[7953]: daemon: select: listen=8 active_threads=0 tvp=NULL
Oct  1 13:58:35 trillian slapd[7953]: daemon: activity on 1 descriptors
Oct  1 13:58:35 trillian slapd[7953]: daemon: activity on:
Oct  1 13:58:35 trillian slapd[7953]:  11r
Oct  1 13:58:35 trillian slapd[7953]: 
Oct  1 13:58:35 trillian slapd[7953]: daemon: read activity on 11
Oct  1 13:58:35 trillian slapd[7953]: connection_get(11)
Oct  1 13:58:35 trillian slapd[7953]: daemon: select: listen=6 active_threads=0 tvp=NULL
Oct  1 13:58:35 trillian slapd[7953]: daemon: select: listen=7 active_threads=0 tvp=NULL
Oct  1 13:58:35 trillian slapd[7953]: daemon: select: listen=8 active_threads=0 tvp=NULL
Oct  1 13:58:35 trillian slapd[7953]: do_extended: oid=1.3.6.1.4.1.1466.20037
Oct  1 13:58:35 trillian slapd[7953]: daemon: activity on 1 descriptors
Oct  1 13:58:35 trillian slapd[7953]: daemon: activity on:
Oct  1 13:58:35 trillian slapd[7953]:  11r
Oct  1 13:58:35 trillian slapd[7953]: 
Oct  1 13:58:35 trillian slapd[7953]: daemon: read activity on 11
Oct  1 13:58:35 trillian slapd[7953]: connection_get(11)
Oct  1 13:58:35 trillian slapd[7953]: daemon: select: listen=6 active_threads=0 tvp=NULL
Oct  1 13:58:35 trillian slapd[7953]: daemon: select: listen=7 active_threads=0 tvp=NULL
Oct  1 13:58:35 trillian slapd[7953]: daemon: select: listen=8 active_threads=0 tvp=NULL
Oct  1 13:58:35 trillian slapd[7953]: daemon: activity on 1 descriptors
Oct  1 13:58:35 trillian slapd[7953]: daemon: activity on:
Oct  1 13:58:35 trillian slapd[7953]:  11r
Oct  1 13:58:35 trillian slapd[7953]: 
Oct  1 13:58:35 trillian slapd[7953]: daemon: read activity on 11
Oct  1 13:58:35 trillian slapd[7953]: connection_get(11)
Oct  1 13:58:35 trillian slapd[7953]: daemon: removing 11
Oct  1 13:58:35 trillian slapd[7953]: conn=5 fd=11 closed

Code: Select all

# emerge --info
Gentoo Base System version 1.12.5
Portage 2.1.1-r1 (default-linux/amd64/2006.1/server, gcc-4.1.1, glibc-2.4-r3, 2.6.17-gentoo-r8 x86_64)
=================================================================
System uname: 2.6.17-gentoo-r8 x86_64 AMD Athlon(tm) 64 Processor 3000+
Last Sync: Sat, 30 Sep 2006 19:00:01 +0000
distcc 2.18.3 x86_64-pc-linux-gnu (protocols 1 and 2) (default port 3632) [disabled]
ccache version 2.3 [enabled]
app-admin/eselect-compiler: [Not Present]
dev-java/java-config: 1.3.0-r2, 2.0.30
dev-lang/python:     2.3.5-r2, 2.4.3-r4
dev-python/pycrypto: 2.0.1-r5
dev-util/ccache:     2.3
dev-util/confcache:  [Not Present]
sys-apps/sandbox:    1.2.17
sys-devel/autoconf:  2.13, 2.59-r7
sys-devel/automake:  1.4_p6, 1.5, 1.6.3, 1.7.9-r1, 1.8.5-r3, 1.9.6-r2
sys-devel/binutils:  2.16.1-r3
sys-devel/gcc-config: 1.3.13-r3
sys-devel/libtool:   1.5.22
virtual/os-headers:  2.6.11-r2
ACCEPT_KEYWORDS="amd64"
AUTOCLEAN="yes"
CBUILD="x86_64-pc-linux-gnu"
CFLAGS="-O2 -march=k8 -pipe -msse3"
CHOST="x86_64-pc-linux-gnu"
CONFIG_PROTECT="/etc /var/bind"
CONFIG_PROTECT_MASK="/etc/env.d /etc/env.d/java/ /etc/gconf /etc/java-config/vms/ /etc/revdep-rebuild /etc/terminfo"
CXXFLAGS="-O2 -march=k8 -pipe -msse3"
DISTDIR="/data/distfiles"
FEATURES="autoconfig ccache distlocks metadata-transfer parallel-fetch sandbox sfperms strict userfetch"
GENTOO_MIRRORS="http://gentoo.inode.at/ ftp://gentoo.inode.at/source/ ftp://ftp.uni-erlangen.de/pub/mirrors/gentoo ftp://sunsite.cnlab-switch.ch/mirror/gentoo "
LANG="en_US.utf8"
MAKEOPTS="-j2"
PKGDIR="/usr/portage/packages"
PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --compress --force --whole-file --delete --delete-after --stats --timeout=180 --exclude='/distfiles' --exclude='/local' --exclude='/packages'"
PORTAGE_TMPDIR="/tmp"
PORTDIR="/usr/portage"
PORTDIR_OVERLAY="/usr/local/portage"
SYNC="rsync://rsync.gentoo.org/gentoo-portage"
USE="amd64 acl acpi apache2 bash-completion berkdb bitmap-fonts bzip2 cli crypt cups dlloader dri elibc_glibc fortran gcj gnutls gpm hal input_devices_evdev input_devices_keyboard input_devices_mouse isdnlog java javacomm javamail kerberos kernel_linux ldap libg++ mailwrapper mbox mysql ncurses nls nptl nptlonly pam pcre perl pic ppds pppd python readline reflection samba sasl session snmp spl ssl tcpd threads truetype truetype-fonts type1-fonts udev unicode userland_GNU video_cards_apm video_cards_ark video_cards_ati video_cards_chips video_cards_cirrus video_cards_cyrix video_cards_dummy video_cards_fbdev video_cards_glint video_cards_i128 video_cards_i810 video_cards_mga video_cards_neomagic video_cards_nv video_cards_rendition video_cards_s3 video_cards_s3virge video_cards_savage video_cards_siliconmotion video_cards_sis video_cards_sisusb video_cards_tdfx video_cards_tga video_cards_trident video_cards_tseng video_cards_v4l video_cards_vesa video_cards_vga video_cards_via video_cards_vmware video_cards_voodoo xerces xml xml2 xmlrpc xorg zlib"
Unset:  CTARGET, EMERGE_DEFAULT_OPTS, INSTALL_MASK, LC_ALL, LDFLAGS, LINGUAS, PORTAGE_RSYNC_EXTRA_OPTS

Code: Select all

# emerge -pv openssh pam pam_ldap
These are the packages that would be merged, in order:

Calculating dependencies     ... done!
[ebuild   R   ] net-misc/openssh-4.3_p2-r5  USE="kerberos ldap pam tcpd -X -X509 -chroot -hpn -ipv6 -libedit (-selinux) -sftplogging -skey -smartcard -static" 0 kB 
[ebuild   R   ] sys-libs/pam-0.78-r3  USE="berkdb -nis -pam_chroot -pam_console -pam_timestamp -pwdb (-selinux)" 0 kB 
[ebuild   R   ] sys-auth/pam_ldap-180  USE="ssl" 0 kB

Authentication does not work with root (local user) or other users (which are in the LDAP directory). I've tried various openssh-4.3_x ebuilds as well as openssh-4.4_p1-r1. I've also tried emerge -eD openssh. Additionally, I've tried different USE flags for openssh. Neither did help.

As you can seen in the LDAP log the PAM thread connects to the server but does not send any LDAP query. I also tried to change /etc/pam.d/sshd to something like

Code: Select all

auth required pam_unix.so

instead of the LDAP authentication in system-auth, but this did not do anything as PAM still tried to connect to the LDAP server, which is weird.

Any input on this would be greatly appreciated. Maybe some knows how to get more verbose PAM debugging output...

Thanks!

aceFruchtsaft · Post by **aceFruchtsaft** » Sun Oct 01, 2006 5:14 pm

Ok, while writing this I realized that even if I changed the auth token in /etc/pam.d/sshd, account, session and password would still depend on LDAP.

So now I've changed /etc/pam.d/sshd to

Code: Select all

#%PAM-1.0

auth       required     pam_unix.so shadow nullok
auth       required     pam_shells.so
auth       required     pam_nologin.so
auth       required     pam_env.so

account         required        pam_unix.so

password        required        pam_cracklib.so retry=3 difok=2 minlen=7 dcredit=2 ocredit=2
password        sufficient      pam_unix.so nullok use_authtok shadow md5
password        required        pam_deny.so

session         required        pam_limits.so
session         required        pam_unix.so
session         required        pam_mkhomedir.so skel=/etc/skel/ umask=0

... and now it actually works for root (all other users are non-local).

So it's an LDAP problem after all....

Still, any ideas would be appereciated.

wynn · Post by **wynn** » Sun Oct 01, 2006 5:20 pm

Just a thought: have you upgraded from openssl 0.9.7 to 0.9.8 recently? Have you still got the old libssl and libcrypto? If so, would it be worthwhile emerge'ng PAM again to get it to use the 0.9.8 ibraries?

revdep-rebuild --library=lib\(ssl\|crypto\).so.0.9.7 might be useful too, it pulls in openldap.

aceFruchtsaft · Post by **aceFruchtsaft** » Sun Oct 01, 2006 6:43 pm

Wow, you were actually right. After checking with genlop I noticed that I didn't re-emerge Openldap since I updated to openssl-0.9.8x (however, I though I did...).
I guess as everything else still successfully authenticated against LDAP I thought the problem must be somewhere else.... now I just wonder why all other services kept working, I'd assume that they all use the same libraries to connect to LDAP with TLS.

Thanks!