[SSSD] sssd/ssh authentication problem

Jakub Hrozek jhrozek at redhat.com
Fri Mar 29 08:18:20 UTC 2013


On Thu, Mar 28, 2013 at 04:34:47PM -0700, Wes Modes wrote:
> 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:
> 

Hi Wes,

> [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,

that's why you set the shell to nologin, right?

> 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

I think here is the problem. While retrieving identity information works
just fine even when the SSSD cannot connect to the remote server,
authentication is only possible online by default (unless
cache_credentials is set to True and there was at least one successfull
authentication to establish the cached credentials).

So I would recommend to also raise the debug_level in the [domain]
section and check why the SSSD cannot connect.

> (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]

PAM error code 9 means PAM_AUTHINFO_UNAVAIL - Underlying authentication
service can not retrieve authentication information. Again, I think this
is because the SSSD can't connect to the server for one reason or
another.

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

su from root won't even consult pam_sss for authentication because typically
the pam stack contains pam_rootok.so which always succeeds if the caller
is root. You could verify that by taking a look at /var/log/secure.



More information about the sssd-devel mailing list