LinuxQuestions.org

LinuxQuestions.org (/questions/)
-   Linux - Enterprise (https://www.linuxquestions.org/questions/linux-enterprise-47/)
-   -   RHEL 6 LDAP now requires TLS (https://www.linuxquestions.org/questions/linux-enterprise-47/rhel-6-ldap-now-requires-tls-843917/)

bweddell 12-06-2011 12:55 PM

I tried setting debug to 5 (pam and domain/default sections) under /etc/sssd/sssd.conf and restarted sssd. Here are the results after attempting a ldap login through ssh:

>sssd.log:
Tue Dec 6 12:43:18 2011) [sssd] [monitor_quit] (0): Monitor received Terminated: terminating children

>sssd_pam.log (I modified user and IP info):
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [accept_priv_fd_handler] (4): Client connected to privileged pipe!
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [sss_cmd_get_version] (5): Received client version [3].
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [sss_cmd_get_version] (5): Offered version [3].
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_cmd_authenticate] (4): entering pam_cmd_authenticate
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): domain: (null)
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): user: testuser
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): rhost: ##.##.##.##
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 1
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 11
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): priv: 1
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 19955
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [sss_dp_send_acct_req_create] (4): Sending request for [default][3][1][name=testuser]
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [sss_dp_get_reply] (4): Got reply (1, 14, Init Groups Failed) from Data Provider
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_check_user_dp_callback] (2): Unable to get information from Data Provider
Error: 1, 14, Init Groups Failed
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_dp_send_req] (4): Sending request with the following data:
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): domain: default
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): user: testuser
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): rhost: ##.##.##.##
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 1
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 11
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): priv: 1
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 19955
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_dom_forwarder] (4): pam_dp_send_req returned 0
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_dp_process_reply] (4): received: [9][default]
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_reply] (4): pam_reply get called.
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [sysdb_cache_auth_get_attrs_done] (4): Cached credentials not available.
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_reply] (4): pam_reply get called.
(Tue Dec 6 12:43:48 2011) [sssd[pam]] [pam_reply] (4): blen: 24
(Tue Dec 6 12:45:43 2011) [sssd[pam]] [client_recv] (5): Client disconnected!


>sssd_default.log (I modified user and IP info):
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for [3][1][name=testuser]
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [fo_resolve_service_send] (4): Trying to resolve service 'LDAP'
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [resolv_gethostbyname_send] (4): Trying to resolve A record of 'testldap.domain.net'
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [set_server_common_status] (4): Marking server 'testldap.domain.net' as 'resolving name'
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [set_server_common_status] (4): Marking server 'testldap.domain.net' as 'name resolved'
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_resolve_server_done] (4): Found address for server testldap.domain.net: [192.168.33.91]
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [sdap_connect_send] (4): Executing START TLS
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [sdap_connect_done] (3): START TLS result: Success(0), (null)
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [simple_bind_send] (4): Executing simple bind as: (null)
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [simple_bind_done] (5): Server returned no controls.
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [simple_bind_done] (3): Bind result: Success(0), (null)
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [fo_set_port_status] (4): Marking port 389 of server 'testldap.domain.net' as 'working'
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [set_server_common_status] (4): Marking server 'testldap.domain.net' as 'working'
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_run_offline_cb] (3): Going offline. Running callbacks.
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 1,14,Init Groups Failed
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_pam_handler] (4): Got request with the following data
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): user: testuser
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): service: sshd
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): tty: ssh
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): ruser:
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 192.168.1.33
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 1
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 11
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 19955
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [sdap_pam_auth_handler] (4): Backend is marked offline, retry later!
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (1, 9, <NULL>) [Provider is Offline (Bad file descriptor)]
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [9][default]
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [9][default]

sgallagh 12-07-2011 06:02 AM

Quote:

Originally Posted by bweddell (Post 4543629)
>sssd_default.log (I modified user and IP info):
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for [3][1][name=testuser]
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [fo_resolve_service_send] (4): Trying to resolve service 'LDAP'
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [resolv_gethostbyname_send] (4): Trying to resolve A record of 'testldap.domain.net'
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [set_server_common_status] (4): Marking server 'testldap.domain.net' as 'resolving name'
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [set_server_common_status] (4): Marking server 'testldap.domain.net' as 'name resolved'
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_resolve_server_done] (4): Found address for server testldap.domain.net: [192.168.33.91]
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [sdap_connect_send] (4): Executing START TLS
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [sdap_connect_done] (3): START TLS result: Success(0), (null)
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [simple_bind_send] (4): Executing simple bind as: (null)
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [simple_bind_done] (5): Server returned no controls.
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [simple_bind_done] (3): Bind result: Success(0), (null)
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [fo_set_port_status] (4): Marking port 389 of server 'testldap.domain.net' as 'working'
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [set_server_common_status] (4): Marking server 'testldap.domain.net' as 'working'
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_run_offline_cb] (3): Going offline. Running callbacks.
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 1,14,Init Groups Failed
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_pam_handler] (4): Got request with the following data
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): user: testuser
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): service: sshd
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): tty: ssh
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): ruser:
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 192.168.1.33
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 1
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 11
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 19955
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [sdap_pam_auth_handler] (4): Backend is marked offline, retry later!
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (1, 9, <NULL>) [Provider is Offline (Bad file descriptor)]
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [9][default]
(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [9][default]

Could you turn the debug level up to 7 and rerun this? I don't know what happened between
Quote:

(Tue Dec 6 12:43:48 2011) [sssd[be[default]]] [set_server_common_status] (4): Marking server 'testldap.domain.net' as 'working'
(Tue Dec 6 12:43:48 2011)
and
Quote:

[sssd[be[default]]] [be_run_offline_cb] (3): Going offline. Running callbacks.

bweddell 12-07-2011 05:29 PM

Here are the results from setting debug to 7:

(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [simple_bind_done] (3): Bind result: Success(0), (null)
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [fo_set_port_status] (4): Marking port 389 of server 'testldap.domain.net' as 'working'
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [set_server_common_status] (4): Marking server 'testldap.domain.net' as 'working'
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(&(uid=testuser)(objectclass=posixAccount))][dc=domain,dc=net].
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [objectClass]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [uid]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [userPassword]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [uidNumber]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [gidNumber]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [gecos]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [homeDirectory]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [loginShell]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [krbPrincipalName]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [cn]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [modifyTimestamp]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowLastChange]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowMin]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowMax]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowWarning]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowInactive]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowExpire]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowFlag]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [krbLastPwdChange]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [krbPasswordExpiration]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [pwdAttribute]
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_get_users_process] (6): Search for users, returned 1 results.
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_save_user_send] (7): Adding original DN [cn=Test User,cn=users,dc=domain,dc=net] to attributes of [testuser].
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_save_user_send] (7): Original memberOf is not available for [testuser].
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_save_user_send] (7): User principal is not available for [testuser].
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [sdap_save_user_send] (6): Storing info for user testuser
(Wed Dec 7 17:18:25 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 0,0,Success
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for [3][1][name=testuser]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(&(uid=testuser)(objectclass=posixAccount))][dc=domain,dc=net].
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [objectClass]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [uid]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [userPassword]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [uidNumber]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [gidNumber]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [gecos]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [homeDirectory]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [loginShell]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [krbPrincipalName]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [cn]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [modifyTimestamp]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowLastChange]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowMin]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowMax]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowWarning]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowInactive]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowExpire]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [shadowFlag]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [krbLastPwdChange]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [krbPasswordExpiration]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [pwdAttribute]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_save_user_send] (7): Adding original DN [cn=Test User,cn=users,dc=domain,dc=net] to attributes of [testuser].
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_save_user_send] (7): Original memberOf is not available for [testuser].
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_save_user_send] (7): User principal is not available for [testuser].
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_save_user_send] (6): Storing info for user testuser
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(&(memberuid=testuser)(objectclass=posixGroup))][dc=domain,dc=net].
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [objectClass]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [cn]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [userPassword]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [gidNumber]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [memberuid]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [modifyTimestamp]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_initgr_rfc2307_update_sysdb_groups] (6): User is not a member of any groups
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sldb_request_callback] (6): LDB Error: 20 (member: value #0 already exists)
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sysdb_op_default_done] (6): Error: 14 (Bad address)
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sysdb_add_group_member_done] (6): Error: 14 (Bad address)
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [be_run_offline_cb] (3): Going offline. Running callbacks.
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 1,14,Init Groups Failed
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [be_pam_handler] (4): Got request with the following data
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): user: testuser
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): service: sshd
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): tty: ssh
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): ruser:
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 192.168.1.33
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 1
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 11
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 5254
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_pam_auth_handler] (4): Backend is marked offline, retry later!
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (1, 9, <NULL>) [Provider is Offline (Bad file descriptor)]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [9][default]
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [9][default]

sgallagh 12-08-2011 06:37 AM

Quote:

Originally Posted by bweddell (Post 4544630)
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sdap_initgr_rfc2307_update_sysdb_groups] (6): User is not a member of any groups
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sldb_request_callback] (6): LDB Error: 20 (member: value #0 already exists)
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sysdb_op_default_done] (6): Error: 14 (Bad address)
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [sysdb_add_group_member_done] (6): Error: 14 (Bad address)
(Wed Dec 7 17:18:28 2011) [sssd[be[default]]] [be_run_offline_cb] (3): Going offline. Running callbacks.

Well, this looks like the problem. Could you verify that you don't have multiple users with the same username or primaryUID in LDAP? (Same for group names and primaryGID for which this user is a member).

Also, please open a bug at https://fedorahosted.org/sssd (you need a username and password from https://admin.fedorahosted.org/accounts)

bweddell 12-08-2011 01:37 PM

I've got some work to do with my LDAP accounts, but that is indeed the problem. I ended up recreating my account and group and all is well. I'm curious though why CentOS5 didn't seem to care about this, but it is working now. Thank you for your help!!!!!

sgallagh 12-09-2011 06:23 AM

Quote:

Originally Posted by bweddell (Post 4545369)
I've got some work to do with my LDAP accounts, but that is indeed the problem. I ended up recreating my account and group and all is well. I'm curious though why CentOS5 didn't seem to care about this, but it is working now. Thank you for your help!!!!!

Well, SSSD is a bit more strict. nss_ldap (which CentOS 5 would have been using) would have allowed these duplicate values, but they would instead cause endless headaches trying to work out which user was ACTUALLY doing what. So in the end, it would actually be more harmful (and harder to figure out).

chenjintao_ii 12-22-2011 07:54 AM

here is the tail of my sssd_default.log file when i restart sssd:

(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [sssm_ldap_auth_init] (7): Service name for discovery set to ldap
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [be_fo_add_service] (6): Failover service already initialized!
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [sdap_service_init] (6): Added URI ldap://xyz.com:389
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [fo_add_server] (3): Adding new server 'xyz.com', to service 'LDAP'
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [main] (1): Backend provider (default) started!
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [id_callback] (4): Got id ack and version (1) from Monitor
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [sbus_server_init_new_connection] (5): Entering.
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [sbus_server_init_new_connection] (5): Adding connection 0x1cf1980.
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [sbus_init_connection] (5): Adding connection 1CF1980
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [sbus_server_init_new_connection] (5): Got a connection
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [be_client_init] (4): Set-up Backend ID timeout [0x1ce8870]
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [sbus_server_init_new_connection] (5): Entering.
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [sbus_server_init_new_connection] (5): Adding connection 0x1cf40d0.
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [sbus_init_connection] (5): Adding connection 1CF40D0
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [sbus_server_init_new_connection] (5): Got a connection
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [be_client_init] (4): Set-up Backend ID timeout [0x1cf48c0]
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [client_registration] (4): Cancel DP ID timeout [0x1ce8870]
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [client_registration] (4): Added Frontend client [PAM]
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [client_registration] (4): Cancel DP ID timeout [0x1cf48c0]
(Sun Dec 11 17:43:32 2011) [sssd[be[default]]] [client_registration] (4): Added Frontend client [NSS]
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [fo_resolve_service_send] (4): Trying to resolve service 'LDAP'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [get_server_status] (7): Status of server 'xyz.com' is 'name not resolved'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [get_port_status] (7): Port status of port 389 for server 'xyz.com' is 'neutral'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [get_server_status] (7): Status of server 'xyz.com' is 'name not resolved'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [resolv_gethostbyname_send] (4): Trying to resolve A record of 'xyz.com'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [set_server_common_status] (4): Marking server 'xyz.com' as 'resolving name'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [set_server_common_status] (4): Marking server 'xyz.com' as 'name resolved'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [be_resolve_server_done] (4): Found address for server xyz.com: [192.168.1.43]
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [sdap_uri_callback] (6): Constructed uri 'ldap://xyz.com:389'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [sdap_uri_callback] (6): Constructed uri 'ldap://xyz.com:389'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [sdap_uri_callback] (6): Constructed uri 'ldap://xyz.com:389'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [sdap_connect_send] (4): Executing START TLS
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [sdap_connect_done] (3): START TLS result: Protocol error(2), unsupported extended operation
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [sdap_connect_done] (3): ldap_install_tls failed: [Connect error] [unsupported extended operation]
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [fo_set_port_status] (4): Marking port 389 of server 'xyz.com' as 'not working'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [be_run_offline_cb] (3): Going offline. Running callbacks.
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [ldap_id_enum_users_done] (1): Failed to enumerate users, retrying later!
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [ldap_id_enumerate_set_timer] (6): Scheduling next enumeration at 1323596922.1916340

it always occur this error: unsupported extended operation.
i have tryed all of the ways can be found on the web include this forum. but it still doesn't work.
what's wrong about my ldap service? I'll appreciate if there's any help.

sgallagh 01-03-2012 08:29 AM

Quote:

Originally Posted by chenjintao_ii (Post 4556157)
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [be_resolve_server_done] (4): Found address for server xyz.com: [192.168.1.43]
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [sdap_uri_callback] (6): Constructed uri 'ldap://xyz.com:389'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [sdap_uri_callback] (6): Constructed uri 'ldap://xyz.com:389'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [sdap_uri_callback] (6): Constructed uri 'ldap://xyz.com:389'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [sdap_connect_send] (4): Executing START TLS
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [sdap_connect_done] (3): START TLS result: Protocol error(2), unsupported extended operation
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [sdap_connect_done] (3): ldap_install_tls failed: [Connect error] [unsupported extended operation]
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [fo_set_port_status] (4): Marking port 389 of server 'xyz.com' as 'not working'
(Sun Dec 11 17:43:42 2011) [sssd[be[default]]] [be_run_offline_cb] (3): Going offline. Running callbacks.



This is a server-side issue. The server is not configured to properly handle TLS requests (which is necessary if you are either setting 'ldap_id_use_start_tls = True' or if you are attempting to authenticate via LDAP).

chenjintao_ii 01-03-2012 09:04 PM

Quote:

Originally Posted by sgallagh (Post 4564640)
This is a server-side issue. The server is not configured to properly handle TLS requests (which is necessary if you are either setting 'ldap_id_use_start_tls = True' or if you are attempting to authenticate via LDAP).

thank you for your prompt, I'll try it.:hattip:

brunodeep 01-20-2012 11:36 AM

I Make the changes in my rhel 6.2:

FORCELEGACY=yes


ldap_tls_reqcert = never


authconfig --disableldaptls --enableldap --enableldapauth --ldapserver=ldap.server.com --ldapbasedn="blablabla" --update


It still try to connect using ldap:




9/??base] with fd [25].
(Fri Jan 20 15:29:59 2012) [sssd[be[default]]] [sdap_sys_connect_done] (4): Executing START TLS
(Fri Jan 20 15:29:59 2012) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xde86a0], connected[1], ops[0xde7f50], ldap[0xdf5440]
(Fri Jan 20 15:29:59 2012) [sssd[be[default]]] [sdap_connect_done] (3): START TLS result: Protocol error(2), unsupported extended operation



Any ideias?

sgallagh 01-21-2012 07:50 AM

Quote:

Originally Posted by brunodeep (Post 4579961)
(Fri Jan 20 15:29:59 2012) [sssd[be[default]]] [sdap_connect_done] (3): START TLS result: Protocol error(2), unsupported extended operation

The problem is server-side. You LDAP server is reporting that it cannot support TLS. This is almost certainly a configuration mistake on the LDAP server. Contact your LDAP admins.

brunodeep 01-23-2012 04:44 AM

i dont think that is a server-side problem
I have SSH via LDAP working on RHEL5.
The problem is only on RHEL6.

My Ldap server have TLS disabled.

sgallagh 01-24-2012 06:07 AM

Quote:

Originally Posted by brunodeep (Post 4581961)
i dont think that is a server-side problem
I have SSH via LDAP working on RHEL5.
The problem is only on RHEL6.

My Ldap server have TLS disabled.

What you have is a conceptual problem right now. The thing you are failing to realize is that by using LDAP for authentication without TLS or SSL, you have an enormous security hole in your environment. Every time any user logs in, their password is being broadcast in plaintext to anyone who cares to listen with a packet sniffer. This means that your environment would be absolutely trivial for an attacker to gain access to.

SSSD does not allow this. Unlike pam_ldap, SSSD will always refuse to broadcast users' passwords. If there is no encryption available on the communication, we throw an error instead of exposing your users.

Also, depending on where you are located (such as the United States), if this is a business network you may be in violation of regulatory rules regarding proper safeguards of passwords. So in conclusion: yes, this is a server-side problem. Your servers MUST be configured to use encryption if you A) want SSSD to work and B) want your network to be secure.

brunodeep 01-24-2012 06:16 AM

I understand your security issue. But there is more difficult to enable the LDAP server SSL for my network.

Also i has used the ldap_auth_disable_tls_never_use_in_production = true in the /etc/sssd/sssd.conf and it dont use TLS.


Thanks for the help

sgallagh 01-25-2012 06:47 AM

Quote:

Originally Posted by brunodeep (Post 4583033)
I understand your security issue. But there is more difficult to enable the LDAP server SSL for my network.

Also i has used the ldap_auth_disable_tls_never_use_in_production = true in the /etc/sssd/sssd.conf and it dont use TLS.


Thanks for the help

I'm trying to impress on you that this is the WRONG approach. Not using SSL because you don't want to be bothered adding certificates is like not locking a bank vault because it would be too inconvenient to have to remember the code. Literally anyone with access to your network can sniff your passwords.

Also, look at the title of that option. It exists solely for the purposes of testing (and is not documented in the manpages for a reason).


All times are GMT -5. The time now is 06:50 AM.