LinuxQuestions.org
Download your favorite Linux distribution at LQ ISO.
Go Back   LinuxQuestions.org > Forums > Enterprise Linux Forums > Linux - Enterprise
User Name
Password
Linux - Enterprise This forum is for all items relating to using Linux in the Enterprise.

Notices


Reply
  Search this Thread
Old 12-06-2011, 12:55 PM   #16
bweddell
LQ Newbie
 
Registered: Jul 2011
Posts: 11

Rep: Reputation: Disabled

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]
 
Click here to see the post LQ members have rated as the most helpful post in this thread.
Old 12-07-2011, 06:02 AM   #17
sgallagh
LQ Newbie
 
Registered: Mar 2011
Posts: 26

Rep: Reputation: 13
Quote:
Originally Posted by bweddell View Post
>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.
 
1 members found this post helpful.
Old 12-07-2011, 05:29 PM   #18
bweddell
LQ Newbie
 
Registered: Jul 2011
Posts: 11

Rep: Reputation: Disabled
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]
 
Old 12-08-2011, 06:37 AM   #19
sgallagh
LQ Newbie
 
Registered: Mar 2011
Posts: 26

Rep: Reputation: 13
Quote:
Originally Posted by bweddell View Post
(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)
 
2 members found this post helpful.
Old 12-08-2011, 01:37 PM   #20
bweddell
LQ Newbie
 
Registered: Jul 2011
Posts: 11

Rep: Reputation: Disabled
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!!!!!
 
Old 12-09-2011, 06:23 AM   #21
sgallagh
LQ Newbie
 
Registered: Mar 2011
Posts: 26

Rep: Reputation: 13
Quote:
Originally Posted by bweddell View Post
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).
 
Old 12-22-2011, 07:54 AM   #22
chenjintao_ii
LQ Newbie
 
Registered: Dec 2011
Posts: 29

Rep: Reputation: Disabled
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.
 
Old 01-03-2012, 08:29 AM   #23
sgallagh
LQ Newbie
 
Registered: Mar 2011
Posts: 26

Rep: Reputation: 13
Quote:
Originally Posted by chenjintao_ii View Post
(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).
 
Old 01-03-2012, 09:04 PM   #24
chenjintao_ii
LQ Newbie
 
Registered: Dec 2011
Posts: 29

Rep: Reputation: Disabled
Quote:
Originally Posted by sgallagh View Post
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.
 
Old 01-20-2012, 11:36 AM   #25
brunodeep
LQ Newbie
 
Registered: Jan 2012
Posts: 4

Rep: Reputation: Disabled
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?
 
Old 01-21-2012, 07:50 AM   #26
sgallagh
LQ Newbie
 
Registered: Mar 2011
Posts: 26

Rep: Reputation: 13
Quote:
Originally Posted by brunodeep View Post
(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.
 
Old 01-23-2012, 04:44 AM   #27
brunodeep
LQ Newbie
 
Registered: Jan 2012
Posts: 4

Rep: Reputation: Disabled
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.
 
Old 01-24-2012, 06:07 AM   #28
sgallagh
LQ Newbie
 
Registered: Mar 2011
Posts: 26

Rep: Reputation: 13
Quote:
Originally Posted by brunodeep View Post
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.
 
Old 01-24-2012, 06:16 AM   #29
brunodeep
LQ Newbie
 
Registered: Jan 2012
Posts: 4

Rep: Reputation: Disabled
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
 
Old 01-25-2012, 06:47 AM   #30
sgallagh
LQ Newbie
 
Registered: Mar 2011
Posts: 26

Rep: Reputation: 13
Quote:
Originally Posted by brunodeep View Post
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).
 
  


Reply


Thread Tools Search this Thread
Search this Thread:

Advanced Search

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is Off
HTML code is Off



Similar Threads
Thread Thread Starter Forum Replies Last Post
problem with TLS connectivity with LDAP tanveer Linux - Server 3 11-29-2009 11:41 PM
samba + ldap requires bind ? RobotiXminD Linux - Server 2 11-10-2009 10:43 AM
Ldap replication using TLS/SSL jitender.rajpal Linux - Networking 0 10-18-2006 07:59 AM
Adobe Acrobate Reader Requires A Plugin-That Requires Open LDAP That Requires Berkely Old_Fogie Slackware 10 05-08-2006 05:04 AM
LDAP TLS lockups blueplazma Linux - Software 2 04-23-2005 01:48 PM

LinuxQuestions.org > Forums > Enterprise Linux Forums > Linux - Enterprise

All times are GMT -5. The time now is 10:11 AM.

Main Menu
Advertisement
My LQ
Write for LQ
LinuxQuestions.org is looking for people interested in writing Editorials, Articles, Reviews, and more. If you'd like to contribute content, let us know.
Main Menu
Syndicate
RSS1  Latest Threads
RSS1  LQ News
Twitter: @linuxquestions
Open Source Consulting | Domain Registration