Hello
Could someone point me in the right direction with what is wrong here,
please? Thank you for any hint.
I want to make ldap authentication without kerberos ( access_provider =
ldap )
TLS/SSL encryption channel is fine, bind user is working, it can find my
testuser and the attributes, but simple bind for checking the password of
the found user is failing with Invalid credentials.
ldapsearch -LLL -h "10.10.10.10" -D "testuser(a)2FA.TEST" -w password -b
"CN=MyUser,CN=Users,DC=2FA,DC=TEST"
is returning the user but sssd fails.
This are the versions I'm using:
ii ldap-utils 2.4.31-1+nmu2 amd64
OpenLDAP utilities
ii libldap-2.4-2:amd64 2.4.31-1+nmu2
amd64 OpenLDAP libraries
ii libsasl2-modules-ldap:amd64
2.1.25.dfsg1-6+deb7u1 amd64 Cyrus SASL -
pluggable authentication modules (LDAP)
ii sssd-ldap 1.11.1-1 amd64
System Security Services Daemon -- LDAP back end
I've checked the pam module and it seams to make that is using the
userPrincipalName for authentication, is this correct?
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_cmd_authenticate] (0x0100):
entering pam_cmd_authenticate
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sss_parse_name_for_domains]
(0x0200): name 'testuser' matched without domain, user is testuser
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sss_parse_name_for_domains]
(0x0200): using default domain [(null)]
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100):
command: PAM_AUTHENTICATE
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100):
domain: not set
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100): user:
testuser
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100):
service: sshd
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100): ruser:
not set
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100): rhost:
192.168.1.1
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100):
authtok type: 1
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100):
newauthtok type: 0
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100):
cli_pid: 5354
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sss_ncache_check_str] (0x2000):
Checking negative cache for [NCE/USER/2FA.TEST/testuser]
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sss_dp_issue_request] (0x0400):
Issuing request for [0x417df0:3:testuser@2FA.TEST]
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sss_dp_get_account_msg]
(0x0400): *Creating request for [2FA.TEST][3][1][name=testuser]*
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sbus_add_timeout] (0x2000): 0xf2c1d0
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sss_dp_internal_get_send]
(0x0400): *Entering request [0x417df0:3:testuser@2FA.TEST]*
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sbus_remove_timeout] (0x2000):
0xf2c1d0
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sbus_dispatch] (0x4000): dbus
conn: 0xf28e30
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sbus_dispatch] (0x4000):
Dispatching.
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sss_dp_get_reply] (0x1000): *Got
reply from Data Provider - DP error code: 3 errno: 34 error message:
Init group lookup failed*
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_check_user_dp_callback]
(0x0040): Unable to get information from Data Provider
Error: 3, 34, Init group lookup failed
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_check_user_search] (0x0100):
Requesting info for [testuser(a)2FA.TEST]
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0xf2dae0
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0xf380a0
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [ldb] (0x4000): Destroying timer
event 0xf380a0 "ltdb_timeout"
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [ldb] (0x4000): Ending timer
event 0xf2dae0 "ltdb_callback"
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_check_user_search] (0x0400):
Returning info for user [testuser(a)2FA.TEST]
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_initgr_cache_set] (0x2000):
[testuser] added to PAM initgroup cache
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_dp_send_req] (0x0100):
Sending request with the following data:
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100):
command: PAM_AUTHENTICATE
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100):
domain: 2FA.TEST
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100): user:
testuser
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100):
service: sshd
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100): ruser:
not set
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100): rhost:
192.168.1.1
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100):
authtok type: 1
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100):
newauthtok type: 0
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_print_data] (0x0100):
cli_pid: 5354
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sbus_add_timeout] (0x2000): 0xf29d40
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_dom_forwarder] (0x0100):
pam_dp_send_req returned 0
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sss_dp_req_destructor] (0x0400):
Deleting request: [0x417df0:3:testuser@2FA.TEST]
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sbus_remove_timeout] (0x2000):
0xf29d40
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sbus_dispatch] (0x4000): dbus
conn: 0xf28e30
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [sbus_dispatch] (0x4000):
Dispatching.
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_dp_process_reply] (0x0100):
received: [7][2FA.TEST]
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_reply] (0x0200): pam_reply
called with result [7].
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [pam_reply] (0x0200): blen: 25
(Thu Dec 5 15:29:49 2013) [sssd[pam]] [reset_idle_timer] (0x4000): Idle
timer re-set for client [0xf31510][18]
(Thu Dec 5 15:29:52 2013) [sssd[pam]] [sbus_dispatch] (0x4000): dbus
conn: 0xf252b0
(Thu Dec 5 15:29:52 2013) [sssd[pam]] [sbus_dispatch] (0x4000):
Dispatching.
(Thu Dec 5 15:29:52 2013) [sssd[pam]] [sbus_message_handler] (0x4000):
Received SBUS method [ping]
(Thu Dec 5 15:29:54 2013) [sssd[pam]] [pam_initgr_cache_remove]
(0x2000): [testuser] removed from PAM initgroup cache
Below is the domain log:
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP'
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [get_server_status]
(0x1000): Status of server '2fa-ad.2FA.TEST' is 'working'
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [get_port_status]
(0x1000): Port status of port 636 for server '2fa-ad.2FA.TEST' is 'working'
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [get_server_status]
(0x1000): Status of server '2fa-ad.2FA.TEST' is 'working'
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]]
[be_resolve_server_process] (0x1000): Saving the first resolved server
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]]
[be_resolve_server_process] (0x0200): Found address for server
2fa-ad.2FA.TEST: [10.10.10.10] TTL 7200
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [sdap_uri_callback]
(0x0400): Constructed uri 'ldaps://2fa-ad.2FA.TEST'
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [auth_resolve_done]
(0x2000): [ldaps://2fa-ad.2FA.TEST] is a secure channel. No need to run
START_TLS
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [sss_ldap_init_send]
(0x4000): Using file descriptor [22] for LDAP connection.
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [sss_ldap_init_send]
(0x0400): Setting 6 seconds timeout for connecting
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]]
[sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to
[ldaps://2fa-ad.2FA.TEST:636/??base] with fd [22].
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [fo_set_port_status]
(0x0100): Marking port 636 of server '2fa-ad.2FA.TEST' as 'working'
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]]
[set_server_common_status] (0x0100): Marking server '2fa-ad.2FA.TEST' as
'working'
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [fo_set_port_status]
(0x0400): Marking port 636 of duplicate server '2fa-ad.2FA.TEST' as
'working'
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [ldb] (0x4000): Added
timed event "ltdb_callback": 0x16f1fe0
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [ldb] (0x4000): Added
timed event "ltdb_timeout": 0x16ee9a0
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [ldb] (0x4000):
Destroying timer event 0x16ee9a0 "ltdb_timeout"
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [ldb] (0x4000): Ending
timer event 0x16f1fe0 "ltdb_callback"
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]]
[find_password_expiration_attributes] (0x4000): No password policy
requested.
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [simple_bind_send]
(0x0100): Executing simple bind as: CN=MyUser,CN=Users,DC=2FA,DC=TEST
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [simple_bind_send]
(0x2000): ldap simple bind sent, msgid = 1
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [sdap_process_result]
(0x2000): Trace: sh[0x16b3f40], connected[1], ops[0x16a9ad0],
ldap[0x16d63c0]
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_BIND]
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [simple_bind_done]
(0x1000): Server returned no controls.
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [simple_bind_done]
(0x0400):*B**ind result: Invalid credentials(49), 80090308: LdapErr:
DSID-0C0903C5, comment: AcceptSecurityContext error, data 52e, v2580*
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]] [sdap_handle_release]
(0x2000): Trace: sh[0x16b3f40], connected[1], ops[(nil)],
ldap[0x16d63c0], destructor_lock[0], release_memory[0]
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]]
[remove_connection_callback] (0x4000): Successfully removed connection
callback.
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]]
[be_pam_handler_callback] (0x0100): Backend returned: (0, 7, <NULL>)
[Success]
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]]
[be_pam_handler_callback] (0x0100): Sending result [7][2FA.TEST]
(Thu Dec 5 15:09:32 2013) [sssd[be[2FA.TEST]]]
[be_pam_handler_callback] (0x0100): Sent result [7][2FA.TEST]
(Thu Dec 5 15:09:40 2013) [sssd[be[2FA.TEST]]] [sbus_dispatch]
(0x4000): dbus conn: 0x169b280
(Thu Dec 5 15:09:40 2013) [sssd[be[2FA.TEST]]] [sbus_dispatch]
(0x4000): Dispatching.
(Thu Dec 5 15:09:40 2013) [sssd[be[2FA.TEST]]] [sbus_message_handler]
(0x4000): Received SBUS method [ping]
--
Dan Cândea
Does God Play Dice?