[SSSD] sssd/ssh authentication problem

Wes Modes wmodes at ucsc.edu
Thu Mar 28 23:34:47 UTC 2013


Hi, I've read a few of the posts to this list that have helped folks
diagnose their auth problems with sssd.  However, I couldn't quite
figure out how to diagnose mine.  Perhaps your expertise can help.

I am running CentOS 6.3 with sssd-1.9.2.  I set up my ldap authorization
like so:

authconfig --enableldap --enableldapauth --enablemkhomedir --ldapserver=ldap.mydomain.edu --ldapbasedn="dc=mydomain,dc=com" --update

After that, most everything worked like magic:

[root at myhost ~]# getent passwd rjohnson
rjohnson:*:30644:30075:Robert Johnson,,831-459-5208,,:/data/home/rjohnson:/bin/nologin

However, I was unable to make ssh for these ldap users work.  It does
work for local users, however.

Now, honestly, I don't want ldap users to ever be able to login via ssh,
however, I suspect getting that to work is the key to getting sftp
working through the ssh system.  Here's what happens when I try to ssh
into myhost.  It is a known/tested user and password combo.

[root at myotherhost]$ ssh jhurt at myhost
jhurt at myhost's password: 
Permission denied, please try again.

And over on myhost with sshd debugging mode:

[root at myhost log]# /usr/sbin/sshd -d -d -d
[snip]
debug1: userauth-request for user jhurt service ssh-connection method password
debug1: attempt 3 failures 0
debug2: input_userauth_request: try method password
debug3: mm_auth_password entering
debug3: mm_request_send entering: type 11
debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD
debug3: mm_request_receive_expect entering: type 12
debug3: mm_request_receive entering
debug3: monitor_read: checking request 11
debug3: PAM: sshpam_passwd_conv called with 1 messages
debug1: PAM: password authentication failed for jhurt: Authentication failure
debug3: mm_answer_authpassword: sending result 0
debug3: mm_request_send entering: type 12
Failed password for jhurt from 128.114.163.2 port 44180 ssh2
debug3: mm_auth_password: user not authenticated
debug3: Wrote 80 bytes for a total of 2045
debug3: mm_request_receive entering

And here's what sssd says in the logs at debug level 9.

(Thu Mar 28 15:47:26 2013) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 1F843B0
(Thu Mar 28 15:47:26 2013) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Mar 28 15:47:26 2013) [sssd[pam]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1f85980][19]
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_cmd_authenticate] (0x0100): entering pam_cmd_authenticate
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'jhurt' matched without domain, user is jhurt
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)]
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): domain: not set
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): user: jhurt
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): service: sshd
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): rhost: myotherhost.mydomain.com
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): authtok size: 5
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): newauthtok size: 0
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6294
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/default/jhurt]
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sss_dp_issue_request] (0x0400): Issuing request for [0x41b300:3:jhurt at default]
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sss_dp_get_account_msg] (0x0400): Creating request for [default][3][1][name=jhurt]
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x1f87da0
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sss_dp_internal_get_send] (0x0400): Entering request [0x41b300:3:jhurt at default]
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x1f87da0
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 1F87950
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 1 errno: 11 error message: Offline
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_check_user_dp_callback] (0x0040): Unable to get information from Data Provider
Error: 1, 11, Offline
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_check_user_search] (0x0100): Requesting info for [jhurt at default]
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1f90e60
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1f90f80
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x1f90f80 "ltdb_timeout"
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [ldb] (0x4000): Ending timer event 0x1f90e60 "ltdb_callback"
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [jhurt at default]
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [jhurt] added to PAM initgroup cache
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): domain: default
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): user: jhurt
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): service: sshd
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): rhost: myotherhost.mydomain.com
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): authtok size: 5
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): newauthtok size: 0
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6294
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x1f816c0
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x41b300:3:jhurt at default]
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x1f816c0
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 1F87950
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_dp_process_reply] (0x0100): received: [9][default]
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [9].
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [pam_reply] (0x0100): blen: 24
(Thu Mar 28 15:47:27 2013) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1f85980][19]
(Thu Mar 28 15:47:32 2013) [sssd[pam]] [pam_initgr_cache_remove] (0x2000): [jhurt] removed from PAM initgroup cache
(Thu Mar 28 15:47:36 2013) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 1F843B0
(Thu Mar 28 15:47:36 2013) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Mar 28 15:47:36 2013) [sssd[pam]] [sbus_message_handler] (0x4000): Received SBUS method [ping]

And here an successful strace of logging into the local machine.

[root at myhost ~]# strace -e open su - jhurt
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/lib64/libpam.so.0", O_RDONLY)    = 3
open("/lib64/libpam_misc.so.0", O_RDONLY) = 3
open("/lib64/libc.so.6", O_RDONLY)      = 3
open("/lib64/libaudit.so.1", O_RDONLY)  = 3
open("/lib64/libdl.so.2", O_RDONLY)     = 3
open("/lib64/libcrypt.so.1", O_RDONLY)  = 3
open("/lib64/libfreebl3.so", O_RDONLY)  = 3
open("/usr/lib/locale/locale-archive", O_RDONLY) = 3
open("/etc/nsswitch.conf", O_RDONLY)    = 3
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/lib64/libnss_files.so.2", O_RDONLY) = 3
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 3
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/lib64/libnss_sss.so.2", O_RDONLY) = 3
open("/lib64/libpthread.so.0", O_RDONLY) = 3
open("/var/lib/sss/mc/passwd", O_RDONLY|O_CLOEXEC) = 3
open("/etc/pam.d/su-l", O_RDONLY)       = 4
open("/etc/pam.d/su", O_RDONLY)         = 5
open("/lib64/security/pam_rootok.so", O_RDONLY) = 6
open("/etc/ld.so.cache", O_RDONLY)      = 6
open("/lib64/libselinux.so.1", O_RDONLY) = 6
open("/etc/pam.d/system-auth", O_RDONLY) = 6
open("/lib64/security/pam_env.so", O_RDONLY) = 7
open("/lib64/security/pam_fprintd.so", O_RDONLY) = 7
open("/etc/ld.so.cache", O_RDONLY)      = 7
open("/usr/lib64/libdbus-glib-1.so.2", O_RDONLY) = 7
open("/lib64/libdbus-1.so.3", O_RDONLY) = 7
open("/lib64/librt.so.1", O_RDONLY)     = 7
open("/lib64/libgobject-2.0.so.0", O_RDONLY) = 7
open("/lib64/libglib-2.0.so.0", O_RDONLY) = 7
open("/lib64/security/pam_unix.so", O_RDONLY) = 7
open("/etc/ld.so.cache", O_RDONLY)      = 7
open("/lib64/libnsl.so.1", O_RDONLY)    = 7
open("/lib64/security/pam_succeed_if.so", O_RDONLY) = 7
open("/lib64/security/pam_sss.so", O_RDONLY) = 7
open("/lib64/security/pam_deny.so", O_RDONLY) = 7
open("/etc/pam.d/su", O_RDONLY)         = 5
open("/etc/pam.d/system-auth", O_RDONLY) = 6
open("/lib64/security/pam_localuser.so", O_RDONLY) = 7
open("/lib64/security/pam_permit.so", O_RDONLY) = 7
open("/etc/pam.d/su", O_RDONLY)         = 5
open("/etc/pam.d/system-auth", O_RDONLY) = 6
open("/lib64/security/pam_cracklib.so", O_RDONLY) = 7
open("/etc/ld.so.cache", O_RDONLY)      = 7
open("/usr/lib64/libcrack.so.2", O_RDONLY) = 7
open("/lib64/security/pam_keyinit.so", O_RDONLY) = 5
open("/etc/pam.d/su", O_RDONLY)         = 5
open("/etc/pam.d/system-auth", O_RDONLY) = 6
open("/lib64/security/pam_limits.so", O_RDONLY) = 7
open("/lib64/security/pam_oddjob_mkhomedir.so", O_RDONLY) = 7
open("/lib64/security/pam_xauth.so", O_RDONLY) = 6
open("/etc/pam.d/other", O_RDONLY)      = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/proc/self/task/6324/attr/current", O_RDONLY) = 4
open("/proc/self/task/6324/attr/current", O_RDONLY) = 4
open("/proc/self/task/6324/attr/prev", O_RDONLY) = 4
open("/selinux/class/passwd/index", O_RDONLY) = 4
open("/selinux/class/passwd/perms", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 4
open("/selinux/class/passwd/perms/crontab", O_RDONLY) = 5
open("/selinux/class/passwd/perms/rootok", O_RDONLY) = 5
open("/selinux/class/passwd/perms/chsh", O_RDONLY) = 5
open("/selinux/class/passwd/perms/chfn", O_RDONLY) = 5
open("/selinux/class/passwd/perms/passwd", O_RDONLY) = 5
open("/selinux/access", O_RDWR)         = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/security/limits.conf", O_RDONLY) = 4
open("/etc/security/limits.d", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 4
open("/usr/lib64/gconv/gconv-modules.cache", O_RDONLY) = 5
open("/etc/security/limits.d/90-nproc.conf", O_RDONLY) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
open("/var/run/utmp", O_RDONLY|O_CLOEXEC) = 4
open("/etc/localtime", O_RDONLY)        = 4
-sh-4.1$ 

And selinux is permissive. 

What is happening here that I can su to this user but cannot ssh in?

Wes


-- 
Wes Modes
Systems Designer, Developer, and Administrator
University Library ITS
University of California, Santa Cruz




More information about the sssd-devel mailing list