On 03/21/2014 01:11 PM, kevin sullivan wrote: I am pretty sure that invalid credentials means that I am typing in the incorrect password, but I promise I am not. I am having an issue where I cannot ssh as a user that is stored in LDAP. I can however use that same user and password to perform a successful ldapsearch and ldapmodify. I am guessing that I have something configured incorrectly. After a day of searching in vain, I have decided to ask people that know better than I do. I see a couple key parts: 1) In the /var/log/sssd/sssd_pam.log -- You can see that pam_reply is called with a result of 6, which I believe is invalid credentials. 2) In the /var/log/sssd/sssd_default.log -- You can see that things seem to be going well until the we get the message 'Bind result: Invalid credentials(49)'. The simple bind doesn't work. How is this different from ldapsearch? I am not an expert in SSSD internals so this is an answer from my general knowledge about the project. SSSD is more picky than simple bind done by ldapsearch or ldapmodify. It requires some kind of authentication. If you do not use any security of the connection it will fail. It seems like TLS is disabled in you setup and bind might be happening in clear. SSSD would not do that. However there can be another issue. May be the server is configured to not to return controls that SSSD expects. For example it expects the server t oreturn information about password aging so that if password needs change the user can be correctly prompted for the change. I would start with the server logs and check if the bind is successful or not. If it fails on the handshake phase this would be probably cased by the first issue. If it goes through fine and bind is successful then it might be related to controls. HTH Dmitri Any thoughts or ideas? Thanks, Kevin Note: I had to severely truncate some of my logs so I could get this email under the 40K size limit. I can send more log information upon request. /etc/password-auth: auth required pam_env.so debug auth [success=done new_authtok_reqd=done auth_err=die perm_denied=die default=ignore] pam_sss.so forward_pass auth sufficient pam_unix.so nullok use_first_pass auth requisite pam_succeed_if.so uid >= 500 quiet auth required pam_deny.so debug /etc/sssd/sssd.conf: [domain/default] debug_level = 9 ldap_id_use_start_tls = False cache_credentials = False ldap_search_base = dc=example,dc=com id_provider = ldap auth_provider = ldap access_provider = ldap ldap_group_member = member chpass_provider = ldap ldap_uri = ldaps://test-server/ ldap_tls_cacert = /etc/openldap/certs/cacert.pem [sssd] debug_level = 9 services = pam config_file_version = 2 domains = default /etc/openldap/slapd.conf: TLSCertificateFile /etc/openldap/certs/server.pem TLSCertificateKeyFile /etc/openldap/certs/server.pem TLSCACertificateFile /etc/openldap/certs/cacert.pem TLSVerifyClient allow # if no access controls are present, the default policy # allows anyone and everyone to read anything but restricts # updates to rootdn. (e.g., "access to * by * read") # # rootdn can always read and write EVERYTHING! # enable users modifying their own passwords. access to dn.exact="" by * read access to attrs=userPassword by self write by anonymous auth by * break access to dn.subtree="dc=example,dc=com" by dn.exact="uid=jharden,ou=Users,dc=example,dc=com" manage by self write by anonymous read by * none ####################################################################### # database definitions ####################################################################### database bdb suffix "dc=example,dc=com" checkpoint 1024 15 /var/log/sssd/sssd_default.log: (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [fo_set_port_status] (0x0100): Marking port 636 of server 'test-server' as 'working' (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [set_server_common_status] (0x0100): Marking server 'test-server' as 'working' (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [dc=example,dc=com] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(uid=jharden)(objectclass=posixAccount))][dc=example,dc=com]. (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 2 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 1 notifies (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: sh[0x16e7840], connected[1], ops[0x1791ec0], ldap[0x16e60a0] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: sh[0x16e7840], connected[1], ops[0x1791ec0], ldap[0x16e60a0] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_parse_entry] (0x4000): OriginalDN: [uid=jharden,ou=Users,dc=example,dc=com]. (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: sh[0x16e7840], connected[1], ops[0x1791ec0], ldap[0x16e60a0] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): start ldb transaction (nesting: 0) (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_initgr_user] (0x4000): Storing the user (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_save_user] (0x4000): Save user (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_save_user] (0x2000): Adding originalDN [uid=jharden,ou=Users,dc=example,dc=com] to attributes of [jharden]. (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_save_user] (0x1000): Original memberOf is not available for [jharden]. (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20140320231721Z] to attributes of [jharden]. (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_save_user] (0x0400): Storing info for user jharden (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_initgr_user] (0x4000): Process user's groups (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_initgr_common_store] (0x2000): Updating memberships for jharden (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): start ldb transaction (nesting: 1) (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): commit ldb transaction (nesting: 1) (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_initgr_done] (0x4000): Initgroups done (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_destroy] (0x4000): releasing operation connection (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_done] (0x4000): releasing operation connection (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [acctinfo_initgroups_callback] (0x0080): NSS Service not conected (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: sh[0x16e7840], connected[1], ops[(nil)], ldap[0x16e60a0] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000): dbus conn: 16DEE20 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000): Dispatching. (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_pam_handler] (0x0100): Got request with the following data (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): domain: default (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): user: jharden (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): service: sshd (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): tty: ssh (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): ruser: (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): rhost: test-server (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): authtok type: 1 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): authtok size: 13 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): newauthtok size: 0 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): priv: 1 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): cli_pid: 24982 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [get_server_status] (0x1000): Status of server 'test-server' is 'working' (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [get_port_status] (0x1000): Port status of port 636 for server 'test-server' is 'working' (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [get_server_status] (0x1000): Status of server 'test-server' is 'working' (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_resolve_server_process] (0x0200): Found address for server test-server: [127.0.0.1] TTL 7200 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [auth_resolve_done] (0x2000): [ldaps://test-server/] is a secure channel. No need to run START_TLS (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sss_ldap_init_send] (0x4000): Using file descriptor [20] for LDAP connection. (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ ldaps://test-server:636/??base] with fd [20]. (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [fo_set_port_status] (0x0100): Marking port 636 of server 'test-server' as 'working' (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [set_server_common_status] (0x0100): Marking server 'test-server' as 'working' (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x17c0950 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x17c0a70 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): Destroying timer event 0x17c0a70 "ltdb_timeout" (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): Ending timer event 0x17c0950 "ltdb_callback" (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [find_password_expiration_attributes] (0x4000): No password policy requested. (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [simple_bind_send] (0x0100): Executing simple bind as: uid=jharden,ou=Users,dc=example,dc=com (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [simple_bind_send] (0x2000): ldap simple bind sent, msgid = 1 (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: sh[0x16e4410], connected[1], ops[0x1794440], ldap[0x1791f40] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_BIND] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [simple_bind_done] (0x1000): Server returned no controls. *(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [simple_bind_done] (0x0400): Bind result: Invalid credentials(49), no errmsg set* (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_handle_release] (0x2000): Trace: sh[0x16e4410], connected[1], ops[(nil)], ldap[0x1791f40], destructor_lock[0], release_memory[0] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 6, <NULL>) [Success] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_pam_handler_callback] (0x0100): Sending result [6][default] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_pam_handler_callback] (0x0100): Sent result [6][default] (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): start ldb transaction (nesting: 0) (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [cleanup_users] (0x4000): Cache expiration is set to 0 days /var/log/sssd/sssd_pam.log: (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [jharden@default] (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [jharden] added to PAM initgroup cache (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data: (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): domain: default (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): user: jharden (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): service: sshd (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): rhost: test-server (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1 (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): authtok size: 13 (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): newauthtok size: 0 (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 24982 (Thu Mar 20 23:25:04 2014) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x2357220 (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Thu Mar 20 23:25:04 2014) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x41b300:3:jharden@default] (Thu Mar 20 23:25:04 2014) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x2357220 (Thu Mar 20 23:25:04 2014) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 23568B0 (Thu Mar 20 23:25:04 2014) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_dp_process_reply] (0x0100): received: [6][default] *(Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [6].* (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_reply] (0x0100): blen: 24 (Thu Mar 20 23:25:04 2014) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x2358760][19] (Thu Mar 20 23:25:04 2014) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x2358760][19] (Thu Mar 20 23:25:04 2014) [sssd[pam]] [client_recv] (0x0200): Client disconnected! (Thu Mar 20 23:25:04 2014) [sssd[pam]] [client_destructor] (0x2000): Terminated client [0x2358760][19] (Thu Mar 20 23:25:09 2014) [sssd[pam]] [pam_initgr_cache_remove] (0x2000): [jharden] removed from PAM initgroup cache _______________________________________________ sssd-users mailing listsssd-users@lists.fedorahosted.orghttps://lists.fedorahosted.org/mailman/listinfo/sssd-users -- Thank you, Dmitri Pal Sr. Engineering Manager for IdM portfolio Red Hat Inc. ------------------------------- Looking to carve out IT costs?www.redhat.com/carveoutcosts/ _______________________________________________ sssd-users mailing list sssd-users(a)lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users

On 03/21/2014 08:13 PM, kevin sullivan wrote: Thanks for the quick response Dmitri. I have been looking through the server logs and trying to find anything that sticks out as an error and I don't know what I am looking for. I can see an initial certificate passing and things seem to proceed without issue from there. I can see where it looks for the different attributes of my user like the group memberships, but I don't see anything that pops out at me. The only error that I see a couple: TLS certificate verification: subject: no certificate, issuer: no certificate, cipher: Camellia-256, security level: high, secret key bits: 256, total key bits: 256, cache hits: 0, cache misses: 4, cache not reusable: 0 connection_read(14): unable to get TLS client DN, error=49 id=1004 I have recently added the option 'ldap_tls_reqcert = allow', so I was hoping this wouldn't actually be an error. I am going to mess around with the certificates some more because it does seem like a good direction to follow. I am connecting to my ldap server via ldaps and I do use certificates when running ldapsearch and ldapmodify. I must be missing something in my sssd.conf. You mentioned that some controls are required for sssd to work properly. Where can I find a good list of these? I hope some of the SSSD team members would be able to give you some hints. I specifically allow access to the RootDSE and I turned off password policy support to hopefully remove another variable from my problem. On Fri, Mar 21, 2014 at 2:14 PM, Dmitri Pal <dpal(a)redhat.com&gt; wrote: > On 03/21/2014 01:11 PM, kevin sullivan wrote: > > I am pretty sure that invalid credentials means that I am typing in the > incorrect password, but I promise I am not. I am having an issue where I > cannot ssh as a user that is stored in LDAP. I can however use that same > user and password to perform a successful ldapsearch and ldapmodify. I am > guessing that I have something configured incorrectly. After a day of > searching in vain, I have decided to ask people that know better than I do. > > I see a couple key parts: > > 1) In the /var/log/sssd/sssd_pam.log -- You can see that pam_reply is > called with a result of 6, which I believe is invalid credentials. > 2) In the /var/log/sssd/sssd_default.log -- You can see that things seem > to be going well until the we get the message 'Bind result: Invalid > credentials(49)'. The simple bind doesn't work. How is this different from > ldapsearch? > > I am not an expert in SSSD internals so this is an answer from my > general knowledge about the project. > SSSD is more picky than simple bind done by ldapsearch or ldapmodify. It > requires some kind of authentication. If you do not use any security of the > connection it will fail. > It seems like TLS is disabled in you setup and bind might be happening in > clear. SSSD would not do that. > However there can be another issue. May be the server is configured to > not to return controls that SSSD expects. For example it expects the server > t oreturn information about password aging so that if password needs change > the user can be correctly prompted for the change. > > I would start with the server logs and check if the bind is successful or > not. If it fails on the handshake phase this would be probably cased by the > first issue. If it goes through fine and bind is successful then it might > be related to controls. > > HTH > Dmitri > > > Any thoughts or ideas? > > Thanks, > > Kevin > > Note: I had to severely truncate some of my logs so I could get this > email under the 40K size limit. I can send more log information upon > request. > > /etc/password-auth: > > auth required pam_env.so debug > auth [success=done new_authtok_reqd=done auth_err=die > perm_denied=die default=ignore] pam_sss.so forward_pass > auth sufficient pam_unix.so nullok use_first_pass > auth requisite pam_succeed_if.so uid >= 500 quiet > auth required pam_deny.so debug > > /etc/sssd/sssd.conf: > > [domain/default] > debug_level = 9 > > ldap_id_use_start_tls = False > cache_credentials = False > ldap_search_base = dc=example,dc=com > id_provider = ldap > auth_provider = ldap > access_provider = ldap > ldap_group_member = member > chpass_provider = ldap > ldap_uri = ldaps://test-server/ > ldap_tls_cacert = /etc/openldap/certs/cacert.pem > > [sssd] > debug_level = 9 > services = pam > config_file_version = 2 > > domains = default > > /etc/openldap/slapd.conf: > > TLSCertificateFile /etc/openldap/certs/server.pem > TLSCertificateKeyFile /etc/openldap/certs/server.pem > TLSCACertificateFile /etc/openldap/certs/cacert.pem > TLSVerifyClient allow > > # if no access controls are present, the default policy > # allows anyone and everyone to read anything but restricts > # updates to rootdn. (e.g., "access to * by * read") > # > # rootdn can always read and write EVERYTHING! > > # enable users modifying their own passwords. > > access to dn.exact="" > by * read > > access to attrs=userPassword > by self write > by anonymous auth > by * break > > access to dn.subtree="dc=example,dc=com" > by dn.exact="uid=jharden,ou=Users,dc=example,dc=com" manage > by self write > by anonymous read > by * none > > ####################################################################### > # database definitions > ####################################################################### > > database bdb > suffix "dc=example,dc=com" > checkpoint 1024 15 > > /var/log/sssd/sssd_default.log: > > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [fo_set_port_status] > (0x0100): Marking port 636 of server 'test-server' as 'working' > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [set_server_common_status] > (0x0100): Marking server 'test-server' as 'working' > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_connect_done] > (0x4000): notify connected to op #1 > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_initgr_send] > (0x4000): Retrieving info for initgroups call > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] > [sdap_get_initgr_next_base] (0x0400): Searching for users with base > [dc=example,dc=com] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] > [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with > [(&(uid=jharden)(objectclass=posixAccount))][dc=example,dc=com]. > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] > [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 2 > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_connect_done] > (0x4000): caching successful connection after 1 notifies > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] > (0x2000): Trace: sh[0x16e7840], connected[1], ops[0x1791ec0], > ldap[0x16e60a0] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] > (0x2000): Trace: ldap_result found nothing! > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] > (0x2000): Trace: sh[0x16e7840], connected[1], ops[0x1791ec0], > ldap[0x16e60a0] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_message] > (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_parse_entry] > (0x4000): OriginalDN: [uid=jharden,ou=Users,dc=example,dc=com]. > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] > (0x2000): Trace: sh[0x16e7840], connected[1], ops[0x1791ec0], > ldap[0x16e60a0] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_message] > (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] > [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg > set > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_initgr_user] > (0x4000): Receiving info for the user > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): start ldb > transaction (nesting: 0) > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_initgr_user] > (0x4000): Storing the user > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_save_user] (0x4000): > Save user > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_save_user] (0x2000): > Adding originalDN [uid=jharden,ou=Users,dc=example,dc=com] to attributes of > [jharden]. > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_save_user] (0x1000): > Original memberOf is not available for [jharden]. > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_attrs_add_ldap_attr] > (0x2000): Adding original mod-Timestamp [20140320231721Z] to attributes of > [jharden]. > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_save_user] > (0x0400): Storing info for user jharden > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_initgr_user] > (0x4000): Process user's groups > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] > [sdap_initgr_common_store] (0x2000): Updating memberships for jharden > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): start ldb > transaction (nesting: 1) > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): commit ldb > transaction (nesting: 1) > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): commit ldb > transaction (nesting: 0) > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_initgr_done] > (0x4000): Initgroups done > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_connect_step] > (0x4000): reusing cached connection > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_destroy] > (0x4000): releasing operation connection > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_done] > (0x4000): releasing operation connection > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] > [acctinfo_initgroups_callback] (0x0080): NSS Service not conected > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [acctinfo_callback] > (0x0100): Request processed. Returned 0,0,Success > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] > (0x2000): Trace: sh[0x16e7840], connected[1], ops[(nil)], ldap[0x16e60a0] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] > (0x2000): Trace: ldap_result found nothing! > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000): > dbus conn: 16DEE20 > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000): > Dispatching. > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sbus_message_handler] > (0x4000): Received SBUS method [pamHandler] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_pam_handler] (0x0100): > Got request with the following data > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > command: PAM_AUTHENTICATE > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > domain: default > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > user: jharden > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > service: sshd > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > tty: ssh > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > ruser: > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > rhost: test-server > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > authtok type: 1 > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > authtok size: 13 > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > newauthtok type: 0 > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > newauthtok size: 0 > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > priv: 1 > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): > cli_pid: 24982 > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [fo_resolve_service_send] > (0x0100): Trying to resolve service 'LDAP' > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [get_server_status] > (0x1000): Status of server 'test-server' is 'working' > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [get_port_status] > (0x1000): Port status of port 636 for server 'test-server' is 'working' > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] > [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 > seconds > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [get_server_status] > (0x1000): Status of server 'test-server' is 'working' > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] > [be_resolve_server_process] (0x1000): Saving the first resolved server > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] > [be_resolve_server_process] (0x0200): Found address for server test-server: > [127.0.0.1] TTL 7200 > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [auth_resolve_done] > (0x2000): [ldaps://test-server/] is a secure channel. No need to run > START_TLS > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sss_ldap_init_send] > (0x4000): Using file descriptor [20] for LDAP connection. > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sss_ldap_init_send] > (0x0400): Setting 6 seconds timeout for connecting > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] > [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ > ldaps://test-server:636/??base] with fd [20]. > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [fo_set_port_status] > (0x0100): Marking port 636 of server 'test-server' as 'working' > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [set_server_common_status] > (0x0100): Marking server 'test-server' as 'working' > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): Added > timed event "ltdb_callback": 0x17c0950 > > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): Added > timed event "ltdb_timeout": 0x17c0a70 > > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): > Destroying timer event 0x17c0a70 "ltdb_timeout" > > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): Ending > timer event 0x17c0950 "ltdb_callback" > > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] > [find_password_expiration_attributes] (0x4000): No password policy > requested. > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [simple_bind_send] > (0x0100): Executing simple bind as: uid=jharden,ou=Users,dc=example,dc=com > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [simple_bind_send] > (0x2000): ldap simple bind sent, msgid = 1 > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] > (0x2000): Trace: sh[0x16e4410], connected[1], ops[0x1794440], > ldap[0x1791f40] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_message] > (0x4000): Message type: [LDAP_RES_BIND] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [simple_bind_done] > (0x1000): Server returned no controls. > *(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [simple_bind_done] > (0x0400): Bind result: Invalid credentials(49), no errmsg set* > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_handle_release] > (0x2000): Trace: sh[0x16e4410], connected[1], ops[(nil)], ldap[0x1791f40], > destructor_lock[0], release_memory[0] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] > [remove_connection_callback] (0x4000): Successfully removed connection > callback. > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_pam_handler_callback] > (0x0100): Backend returned: (0, 6, <NULL>) [Success] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_pam_handler_callback] > (0x0100): Sending result [6][default] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_pam_handler_callback] > (0x0100): Sent result [6][default] > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): start ldb > transaction (nesting: 0) > (Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [cleanup_users] (0x4000): > Cache expiration is set to 0 days > > /var/log/sssd/sssd_pam.log: > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_check_user_search] > (0x0400): Returning info for user [jharden@default] > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_initgr_cache_set] (0x2000): > [jharden] added to PAM initgroup cache > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_dp_send_req] (0x0100): > Sending request with the following data: > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): > command: PAM_AUTHENTICATE > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): domain: > default > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): user: > jharden > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): > service: sshd > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): ruser: > not set > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): rhost: > test-server > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): authtok > type: 1 > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): authtok > size: 13 > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): > newauthtok type: 0 > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): > newauthtok size: 0 > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_print_data] (0x0100): > cli_pid: 24982 > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [sbus_add_timeout] (0x2000): > 0x2357220 > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_dom_forwarder] (0x0100): > pam_dp_send_req returned 0 > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [sss_dp_req_destructor] (0x0400): > Deleting request: [0x41b300:3:jharden@default] > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [sbus_remove_timeout] (0x2000): > 0x2357220 > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [sbus_dispatch] (0x4000): dbus > conn: 23568B0 > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [sbus_dispatch] (0x4000): > Dispatching. > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_dp_process_reply] (0x0100): > received: [6][default] > *(Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_reply] (0x0200): pam_reply > called with result [6].* > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [pam_reply] (0x0100): blen: 24 > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [reset_idle_timer] (0x4000): Idle > timer re-set for client [0x2358760][19] > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [reset_idle_timer] (0x4000): Idle > timer re-set for client [0x2358760][19] > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [client_recv] (0x0200): Client > disconnected! > (Thu Mar 20 23:25:04 2014) [sssd[pam]] [client_destructor] (0x2000): > Terminated client [0x2358760][19] > (Thu Mar 20 23:25:09 2014) [sssd[pam]] [pam_initgr_cache_remove] > (0x2000): [jharden] removed from PAM initgroup cache > > > _______________________________________________ > sssd-users mailing listsssd-users@lists.fedorahosted.orghttps://lists.fedorahosted.org/mailman/listinfo/sssd-users > > > > -- > Thank you, > Dmitri Pal > > Sr. Engineering Manager for IdM portfolio > Red Hat Inc. > > > ------------------------------- > Looking to carve out IT costs?www.redhat.com/carveoutcosts/ > > > _______________________________________________ > sssd-users mailing list > sssd-users(a)lists.fedorahosted.org > https://lists.fedorahosted.org/mailman/listinfo/sssd-users > > -- Thank you, Dmitri Pal Sr. Engineering Manager for IdM portfolio Red Hat Inc. ------------------------------- Looking to carve out IT costs?www.redhat.com/carveoutcosts/ _______________________________________________ sssd-users mailing list sssd-users(a)lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users

Thanks for the response Jakub! I couldn't run your command exactly because I don't use the start_tls command, I run everything over ldaps. I was able to bind anonymously using this command: # ldapsearch -H "ldaps://test-server/" -b "uid=jharden,ou=Users,dc=example,dc=com" I can even bind as the user using this command: # ldapsearch -H "ldaps://test-server/" -b "uid=jharden,ou=Users,dc=example,dc=com" -D "uid=jharden,ou=Users,dc=example,dc=com" -W I remade my CA, my server certificate, and my client certificate to make sure that I wasn't screwing something up with the certificates. Things still work with ldapsearch, but not with sssd.

According to the logs your password has 13 characters, does this make sense?

You PAM configuration is a bit unusual, because you have pam_sss first and the pam_unix. Can you try to switch the order?

return code 49 (0x31 LDAP_INVALID_CREDENTIALS) is return only if there is problem with certificate.

That's odd. Which version of SSSD are you using on which platform?

Can you use strace to trace the authentication process form the sshd side? Some thing like strace -o /tmp/strace.out -s 256 -p PID_of_the_main_sshd_process

On Mon, Mar 24, 2014 at 06:25:36PM -0400, kevin sullivan wrote: > Lukas and Sumit, thanks for your responses. > > >According to the logs your password has > >13 characters, does this make sense? > No, my password doesn't have 13 characters. I did notice that no matter > what I typed, the authtok size was always 13. > That's odd. Which version of SSSD are you using on which platform? Can you use strace to trace the authentication process form the sshd side? Some thing like strace -o /tmp/strace.out -s 256 -p PID_of_the_main_sshd_process should work. The output will contain your password, please send the file to me directly and not to the list. From the output I would be able to see if the 13 character password is send to SSSD already from the sshd. bye, Sumit _______________________________________________ sssd-users mailing list sssd-users(a)lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users