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
#######################################################################
databasebdb
suffix"dc=example,dc=com"
checkpoint1024 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 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?