Hi guys, Again I need your help... I'm using and I configured a domain/my_ldap. During the startup I see these logs:
[cut] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is 'neutral' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 5 seconds (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_is_address] (0x4000): [ldap01.dont.mind.it] does not look like an IP address (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_gethostbyname_step] (0x2000): Querying files (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'ldap01.dont.mind.it' in files (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [set_server_common_status] (0x0100): Marking server 'ldap01.dont.mind.it' as 'resolving name' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [set_server_common_status] (0x0100): Marking server 'ldap01.dont.mind.it' as 'name resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_resolve_server_done] (0x0100): Found address for server ldap01.dont.mind.it: [192.168.146.128] TTL 7200 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldap://ldap01.dont.mind.it:389' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] (0x4000): Using file descriptor [24] for LDAP connection. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://ldap01.dont.mind.it:389/??base] with fd [24]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_entry] (0x4000): OriginalDN: []. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_done] (0x4000): Got rootdse (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_naming_context] (0x0200): Using value from [namingContexts] as naming context. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [dc=dont,dc=mind.it]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_search_base] (0x0100): Search base added: [SUDO][dc=dont.mind.it][SUBTREE][] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_server_opts_from_rootdse] (0x0200): No known USN scheme is supported by this server! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_server_opts_from_rootdse] (0x0200): Will use modification timestamp as usn! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'ldap01.dont.mind.it' as 'not working' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_handle_release] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[(nil)], ldap[0x7f6ec4b579c0], destructor_lock[0], release_memory[0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0010): *Authentication mechanism not Supported by server* (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x4000): attempting failover retry on op #1 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is 'not working' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0020): No available servers for service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0020): Failed to connect, going offline (5 [Input/output error]) (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_mark_offline] (0x2000): Going offline! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_run_offline_cb] (0x0080): Going offline. Running callbacks. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x4000): notify offline to op #1 [cut]
My LDAP server is OpenLDAP. and I have configured the tls part.
[root@fedora16 ~]# netstat -ntlp |grep slapd tcp 0 0 0.0.0.0:636 0.0.0.0:* LISTEN 2951/slapd tcp 0 0 0.0.0.0:389 0.0.0.0:* LISTEN 2951/slapd tcp 0 0 :::636 :::* LISTEN 2951/slapd tcp 0 0 :::389 :::* LISTEN 2951/slapd
This is the interesting part of my domain/my_ldap section of sssd.conf
[domain/my_ldap] description = LDAP Users domain min_id = 7000 max_id = 8000 timeout = 10 enumerate = TRUE entry_cache_timeout = 5400 cache_credentials = TRUE account_cache_expiration = 0 id_provider = ldap use_fully_qualified_names = FALSE auth_provider = ldap access_provider = permit chpass_provider = ldap lookup_family_order = ipv4_first dns_resolver_timeout = 5 #dns_discovery_domain = #override_gid = case_sensitive = True
ldap_uri = ldap://ldap01.dont.mind.it:389 ldap_chpass_uri = ldap://ldap01.dont.mind.it:389 ldap_search_base = dc=dont,dc=mind.it?sub?(objectClass=inetOrgPerson) ldap_schema = rfc2307bis ldap_default_bind_dn = cn=mydn,dc=dont,dc=mind.it ldap_default_authtok_type = pippo #ldap_default_authtok ldap_user_object_class = posixAccount ldap_user_name = uid ldap_user_uid_number = uidNumber ldap_user_gid_number = gidNumber ldap_user_gecos = gecos ldap_user_home_directory = homeDirectory ldap_user_shell = loginShell ldap_user_uuid = entryUUID ldap_user_modify_timestamp = modifyTimestamp ldap_user_shadow_last_change = shadowLastChange ldap_user_shadow_min = shadowMin
#### INIZIO - SSL/TLS #### # # Imposto la richiesta e la validazione del certificato ldap_tls_reqcert = demand # #ldap_tls_cacert = ldap_tls_cacertdir = /etc/pki/tls/certs #ldap_tls_cert = #ldap_tls_key = #ldap_tls_cipher_suite = ldap_id_use_start_tls = false #### FINE - SSL/TLS ####
Could you help me in understanding what is the cause of the backend discard?
Thanks a lot as usual Marco
On Tue, 2012-02-07 at 14:04 +0100, Marco Pizzoli wrote:
Hi guys, Again I need your help... I'm using and I configured a domain/my_ldap. During the startup I see these logs:
[cut] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is 'neutral' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 5 seconds (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_is_address] (0x4000): [ldap01.dont.mind.it] does not look like an IP address (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_gethostbyname_step] (0x2000): Querying files (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'ldap01.dont.mind.it' in files (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [set_server_common_status] (0x0100): Marking server 'ldap01.dont.mind.it' as 'resolving name' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [set_server_common_status] (0x0100): Marking server 'ldap01.dont.mind.it' as 'name resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_resolve_server_done] (0x0100): Found address for server ldap01.dont.mind.it: [192.168.146.128] TTL 7200 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldap://ldap01.dont.mind.it:389' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] (0x4000): Using file descriptor [24] for LDAP connection. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://ldap01.dont.mind.it:389/??base] with fd [24]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_entry] (0x4000): OriginalDN: []. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_done] (0x4000): Got rootdse (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_naming_context] (0x0200): Using value from [namingContexts] as naming context. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [dc=dont,dc=mind.it]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_search_base] (0x0100): Search base added: [SUDO][dc=dont.mind.it][SUBTREE][] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_server_opts_from_rootdse] (0x0200): No known USN scheme is supported by this server! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_server_opts_from_rootdse] (0x0200): Will use modification timestamp as usn! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'ldap01.dont.mind.it' as 'not working' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_handle_release] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[(nil)], ldap[0x7f6ec4b579c0], destructor_lock[0], release_memory[0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0010): Authentication mechanism not Supported by server (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x4000): attempting failover retry on op #1 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is 'not working' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0020): No available servers for service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0020): Failed to connect, going offline (5 [Input/output error]) (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_mark_offline] (0x2000): Going offline! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_run_offline_cb] (0x0080): Going offline. Running callbacks. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x4000): notify offline to op #1 [cut]
My LDAP server is OpenLDAP. and I have configured the tls part.
[root@fedora16 ~]# netstat -ntlp |grep slapd tcp 0 0 0.0.0.0:636 0.0.0.0:* LISTEN 2951/slapd tcp 0 0 0.0.0.0:389 0.0.0.0:* LISTEN 2951/slapd tcp 0 0 :::636 :::* LISTEN 2951/slapd tcp 0 0 :::389 :::* LISTEN 2951/slapd
This is the interesting part of my domain/my_ldap section of sssd.conf
[domain/my_ldap] description = LDAP Users domain min_id = 7000 max_id = 8000 timeout = 10 enumerate = TRUE entry_cache_timeout = 5400 cache_credentials = TRUE account_cache_expiration = 0 id_provider = ldap use_fully_qualified_names = FALSE auth_provider = ldap access_provider = permit chpass_provider = ldap lookup_family_order = ipv4_first dns_resolver_timeout = 5 #dns_discovery_domain = #override_gid = case_sensitive = True
ldap_uri = ldap://ldap01.dont.mind.it:389 ldap_chpass_uri = ldap://ldap01.dont.mind.it:389 ldap_search_base = dc=dont,dc=mind.it?sub?(objectClass=inetOrgPerson) ldap_schema = rfc2307bis ldap_default_bind_dn = cn=mydn,dc=dont,dc=mind.it ldap_default_authtok_type = pippo #ldap_default_authtok ldap_user_object_class = posixAccount ldap_user_name = uid ldap_user_uid_number = uidNumber ldap_user_gid_number = gidNumber ldap_user_gecos = gecos ldap_user_home_directory = homeDirectory ldap_user_shell = loginShell ldap_user_uuid = entryUUID ldap_user_modify_timestamp = modifyTimestamp ldap_user_shadow_last_change = shadowLastChange ldap_user_shadow_min = shadowMin
#### INIZIO - SSL/TLS #### # # Imposto la richiesta e la validazione del certificato ldap_tls_reqcert = demand # #ldap_tls_cacert = ldap_tls_cacertdir = /etc/pki/tls/certs #ldap_tls_cert = #ldap_tls_key = #ldap_tls_cipher_suite = ldap_id_use_start_tls = false #### FINE - SSL/TLS ####
Could you help me in understanding what is the cause of the backend discard?
Can you tell us if it works if you do:
ldapsearch -H ldap://ldap.dont.mind.it -x -w \ -D cn=mydn,dc=dont,dc=mind.it -b dc=dont,dc=mind.it \ objectClass=inetOrgPerson
On Tue, Feb 7, 2012 at 2:10 PM, Stephen Gallagher sgallagh@redhat.comwrote:
On Tue, 2012-02-07 at 14:04 +0100, Marco Pizzoli wrote:
Hi guys, Again I need your help... I'm using and I configured a domain/my_ldap. During the startup I see these logs:
[cut] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is 'neutral' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 5 seconds (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_is_address] (0x4000): [ldap01.dont.mind.it] does not look like an IP address (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_gethostbyname_step] (0x2000): Querying files (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'ldap01.dont.mind.it' in files (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [set_server_common_status] (0x0100): Marking server 'ldap01.dont.mind.it' as 'resolving name' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [set_server_common_status] (0x0100): Marking server 'ldap01.dont.mind.it' as 'name resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_resolve_server_done] (0x0100): Found address for server ldap01.dont.mind.it: [192.168.146.128] TTL 7200 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldap://ldap01.dont.mind.it:389' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] (0x4000): Using file descriptor [24] for LDAP connection. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://ldap01.dont.mind.it:389/??base] with fd [24]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_entry] (0x4000): OriginalDN: []. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_done] (0x4000): Got rootdse (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_naming_context] (0x0200): Using value from [namingContexts] as naming context. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [dc=dont,dc=mind.it]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_search_base] (0x0100): Search base added: [SUDO][dc=dont.mind.it][SUBTREE][] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_server_opts_from_rootdse] (0x0200): No known USN scheme is supported by this server! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_server_opts_from_rootdse] (0x0200): Will use modification timestamp as usn! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'ldap01.dont.mind.it' as 'not working' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_handle_release] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[(nil)], ldap[0x7f6ec4b579c0], destructor_lock[0], release_memory[0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0010): Authentication mechanism not Supported by server (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x4000): attempting failover retry on op #1 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is 'not working' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0020): No available servers for service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0020): Failed to connect, going offline (5 [Input/output error]) (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_mark_offline] (0x2000): Going offline! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_run_offline_cb] (0x0080): Going offline. Running callbacks. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x4000): notify offline to op #1 [cut]
My LDAP server is OpenLDAP. and I have configured the tls part.
[root@fedora16 ~]# netstat -ntlp |grep slapd tcp 0 0 0.0.0.0:636 0.0.0.0:* LISTEN 2951/slapd tcp 0 0 0.0.0.0:389 0.0.0.0:* LISTEN 2951/slapd tcp 0 0 :::636 :::* LISTEN 2951/slapd tcp 0 0 :::389 :::* LISTEN 2951/slapd
This is the interesting part of my domain/my_ldap section of sssd.conf
[domain/my_ldap] description = LDAP Users domain min_id = 7000 max_id = 8000 timeout = 10 enumerate = TRUE entry_cache_timeout = 5400 cache_credentials = TRUE account_cache_expiration = 0 id_provider = ldap use_fully_qualified_names = FALSE auth_provider = ldap access_provider = permit chpass_provider = ldap lookup_family_order = ipv4_first dns_resolver_timeout = 5 #dns_discovery_domain = #override_gid = case_sensitive = True
ldap_uri = ldap://ldap01.dont.mind.it:389 ldap_chpass_uri = ldap://ldap01.dont.mind.it:389 ldap_search_base = dc=dont,dc=mind.it?sub?(objectClass=inetOrgPerson)http://mind.it?sub?%28objectClass=inetOrgPerson%29 ldap_schema = rfc2307bis ldap_default_bind_dn = cn=mydn,dc=dont,dc=mind.it ldap_default_authtok_type = pippo #ldap_default_authtok ldap_user_object_class = posixAccount ldap_user_name = uid ldap_user_uid_number = uidNumber ldap_user_gid_number = gidNumber ldap_user_gecos = gecos ldap_user_home_directory = homeDirectory ldap_user_shell = loginShell ldap_user_uuid = entryUUID ldap_user_modify_timestamp = modifyTimestamp ldap_user_shadow_last_change = shadowLastChange ldap_user_shadow_min = shadowMin
#### INIZIO - SSL/TLS #### # # Imposto la richiesta e la validazione del certificato ldap_tls_reqcert = demand # #ldap_tls_cacert = ldap_tls_cacertdir = /etc/pki/tls/certs #ldap_tls_cert = #ldap_tls_key = #ldap_tls_cipher_suite = ldap_id_use_start_tls = false #### FINE - SSL/TLS ####
Could you help me in understanding what is the cause of the backend discard?
Can you tell us if it works if you do:
ldapsearch -H ldap://ldap.dont.mind.it -x -w \ -D cn=mydn,dc=dont,dc=mind.it -b dc=dont,dc=mind.it \ objectClass=inetOrgPerson
Hi, yes it works. Obviously I posted a camoufled binddn, basedn, etc...
By executing your ldapsearch I obtain this: [cut] # search result search: 2 result: 0 Success
# numResponses: 164 # numEntries: 163
I already checked by tcpdump-ing the dialog between sssd and the ldap server and I saw only one ldapsearch executed, and this was simply against the rootDSE. I expected to see another one against my user db / basedn.
Thanks Marco
On Tue, Feb 7, 2012 at 2:10 PM, Stephen Gallagher
sgallagh@redhat.comwrote:
On Tue, 2012-02-07 at 14:04 +0100, Marco Pizzoli wrote:
Hi guys, Again I need your help... I'm using and I configured a domain/my_ldap. During the startup I see these logs:
[cut] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is 'neutral' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 5 seconds (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_is_address] (0x4000): [ldap01.dont.mind.it] does not look like an IP address (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_gethostbyname_step] (0x2000): Querying files (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'ldap01.dont.mind.it' in files (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [set_server_common_status] (0x0100): Marking server 'ldap01.dont.mind.it' as 'resolving name' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [set_server_common_status] (0x0100): Marking server 'ldap01.dont.mind.it' as 'name resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_resolve_server_done] (0x0100): Found address for server ldap01.dont.mind.it: [192.168.146.128] TTL 7200 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldap://ldap01.dont.mind.it:389' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] (0x4000): Using file descriptor [24] for LDAP connection. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://ldap01.dont.mind.it:389/??base] with fd [24]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_entry] (0x4000): OriginalDN: []. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_done] (0x4000): Got rootdse (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_naming_context] (0x0200): Using value from [namingContexts] as naming context. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [dc=dont,dc=mind.it]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_search_base] (0x0100): Search base added: [SUDO][dc=dont.mind.it][SUBTREE][] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_server_opts_from_rootdse] (0x0200): No known USN scheme is supported by this server! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_server_opts_from_rootdse] (0x0200): Will use modification timestamp as usn! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'ldap01.dont.mind.it' as 'not working' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_handle_release] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[(nil)], ldap[0x7f6ec4b579c0], destructor_lock[0], release_memory[0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0010): Authentication mechanism not Supported by server (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x4000): attempting failover retry on op #1 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is 'not working' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0020): No available servers for service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0020): Failed to connect, going offline (5 [Input/output error]) (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_mark_offline] (0x2000): Going offline! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_run_offline_cb] (0x0080): Going offline. Running callbacks. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x4000): notify offline to op #1 [cut]
My LDAP server is OpenLDAP. and I have configured the tls part.
[root@fedora16 ~]# netstat -ntlp |grep slapd tcp 0 0 0.0.0.0:636 0.0.0.0:* LISTEN 2951/slapd tcp 0 0 0.0.0.0:389 0.0.0.0:* LISTEN 2951/slapd tcp 0 0 :::636 :::* LISTEN 2951/slapd tcp 0 0 :::389 :::* LISTEN 2951/slapd
This is the interesting part of my domain/my_ldap section of sssd.conf
[domain/my_ldap] description = LDAP Users domain min_id = 7000 max_id = 8000 timeout = 10 enumerate = TRUE entry_cache_timeout = 5400 cache_credentials = TRUE account_cache_expiration = 0 id_provider = ldap use_fully_qualified_names = FALSE auth_provider = ldap access_provider = permit chpass_provider = ldap lookup_family_order = ipv4_first dns_resolver_timeout = 5 #dns_discovery_domain = #override_gid = case_sensitive = True
ldap_uri = ldap://ldap01.dont.mind.it:389 ldap_chpass_uri = ldap://ldap01.dont.mind.it:389 ldap_search_base = dc=dont,dc=mind.it?sub?(objectClass=inetOrgPerson)http://mind.it?sub? %28objectClass=inetOrgPerson%29 ldap_schema = rfc2307bis ldap_default_bind_dn = cn=mydn,dc=dont,dc=mind.it ldap_default_authtok_type = pippo #ldap_default_authtok ldap_user_object_class = posixAccount ldap_user_name = uid ldap_user_uid_number = uidNumber ldap_user_gid_number = gidNumber ldap_user_gecos = gecos ldap_user_home_directory = homeDirectory ldap_user_shell = loginShell ldap_user_uuid = entryUUID ldap_user_modify_timestamp = modifyTimestamp ldap_user_shadow_last_change = shadowLastChange ldap_user_shadow_min = shadowMin
#### INIZIO - SSL/TLS #### # # Imposto la richiesta e la validazione del certificato ldap_tls_reqcert = demand # #ldap_tls_cacert = ldap_tls_cacertdir = /etc/pki/tls/certs #ldap_tls_cert = #ldap_tls_key = #ldap_tls_cipher_suite = ldap_id_use_start_tls = false #### FINE - SSL/TLS ####
Could you help me in understanding what is the cause of the backend discard?
Can you tell us if it works if you do:
ldapsearch -H ldap://ldap.dont.mind.it -x -w \ -D cn=mydn,dc=dont,dc=mind.it -b dc=dont,dc=mind.it \ objectClass=inetOrgPerson
Hi, yes it works. Obviously I posted a camoufled binddn, basedn, etc...
I think you should also try the command with -ZZ argument to test if TLS initialization isn't getting in your way. Also please check that /etc/pki/tls/certs contains hashes (symlinks) of certificates you wish to use.
By executing your ldapsearch I obtain this: [cut] # search result search: 2 result: 0 Success
# numResponses: 164 # numEntries: 163
I already checked by tcpdump-ing the dialog between sssd and the ldap server and I saw only one ldapsearch executed, and this was simply against the rootDSE. I expected to see another one against my user db / basedn.
Jan
On Tue, 2012-02-07 at 14:32 +0100, Jan Zelený wrote:
On Tue, Feb 7, 2012 at 2:10 PM, Stephen Gallagher
sgallagh@redhat.comwrote:
On Tue, 2012-02-07 at 14:04 +0100, Marco Pizzoli wrote:
Hi guys, Again I need your help... I'm using and I configured a domain/my_ldap. During the startup I see these logs:
[cut] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is 'neutral' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 5 seconds (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_is_address] (0x4000): [ldap01.dont.mind.it] does not look like an IP address (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_gethostbyname_step] (0x2000): Querying files (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'ldap01.dont.mind.it' in files (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [set_server_common_status] (0x0100): Marking server 'ldap01.dont.mind.it' as 'resolving name' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [set_server_common_status] (0x0100): Marking server 'ldap01.dont.mind.it' as 'name resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_resolve_server_done] (0x0100): Found address for server ldap01.dont.mind.it: [192.168.146.128] TTL 7200 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldap://ldap01.dont.mind.it:389' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] (0x4000): Using file descriptor [24] for LDAP connection. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://ldap01.dont.mind.it:389/??base] with fd [24]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_entry] (0x4000): OriginalDN: []. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_done] (0x4000): Got rootdse (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_naming_context] (0x0200): Using value from [namingContexts] as naming context. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [dc=dont,dc=mind.it]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_search_base] (0x0100): Search base added: [SUDO][dc=dont.mind.it][SUBTREE][] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_server_opts_from_rootdse] (0x0200): No known USN scheme is supported by this server! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_server_opts_from_rootdse] (0x0200): Will use modification timestamp as usn! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'ldap01.dont.mind.it' as 'not working' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_handle_release] (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[(nil)], ldap[0x7f6ec4b579c0], destructor_lock[0], release_memory[0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0010): Authentication mechanism not Supported by server (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x4000): attempting failover retry on op #1 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is 'not working' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0020): No available servers for service 'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0020): Failed to connect, going offline (5 [Input/output error]) (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_mark_offline] (0x2000): Going offline! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_run_offline_cb] (0x0080): Going offline. Running callbacks. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x4000): notify offline to op #1 [cut]
My LDAP server is OpenLDAP. and I have configured the tls part.
[root@fedora16 ~]# netstat -ntlp |grep slapd tcp 0 0 0.0.0.0:636 0.0.0.0:* LISTEN 2951/slapd tcp 0 0 0.0.0.0:389 0.0.0.0:* LISTEN 2951/slapd tcp 0 0 :::636 :::* LISTEN 2951/slapd tcp 0 0 :::389 :::* LISTEN 2951/slapd
This is the interesting part of my domain/my_ldap section of sssd.conf
[domain/my_ldap] description = LDAP Users domain min_id = 7000 max_id = 8000 timeout = 10 enumerate = TRUE entry_cache_timeout = 5400 cache_credentials = TRUE account_cache_expiration = 0 id_provider = ldap use_fully_qualified_names = FALSE auth_provider = ldap access_provider = permit chpass_provider = ldap lookup_family_order = ipv4_first dns_resolver_timeout = 5 #dns_discovery_domain = #override_gid = case_sensitive = True
ldap_uri = ldap://ldap01.dont.mind.it:389 ldap_chpass_uri = ldap://ldap01.dont.mind.it:389 ldap_search_base = dc=dont,dc=mind.it?sub?(objectClass=inetOrgPerson)http://mind.it?sub? %28objectClass=inetOrgPerson%29 ldap_schema = rfc2307bis ldap_default_bind_dn = cn=mydn,dc=dont,dc=mind.it ldap_default_authtok_type = pippo #ldap_default_authtok ldap_user_object_class = posixAccount ldap_user_name = uid ldap_user_uid_number = uidNumber ldap_user_gid_number = gidNumber ldap_user_gecos = gecos ldap_user_home_directory = homeDirectory ldap_user_shell = loginShell ldap_user_uuid = entryUUID ldap_user_modify_timestamp = modifyTimestamp ldap_user_shadow_last_change = shadowLastChange ldap_user_shadow_min = shadowMin
#### INIZIO - SSL/TLS #### # # Imposto la richiesta e la validazione del certificato ldap_tls_reqcert = demand # #ldap_tls_cacert = ldap_tls_cacertdir = /etc/pki/tls/certs #ldap_tls_cert = #ldap_tls_key = #ldap_tls_cipher_suite = ldap_id_use_start_tls = false #### FINE - SSL/TLS ####
Could you help me in understanding what is the cause of the backend discard?
Can you tell us if it works if you do:
ldapsearch -H ldap://ldap.dont.mind.it -x -w \ -D cn=mydn,dc=dont,dc=mind.it -b dc=dont,dc=mind.it \ objectClass=inetOrgPerson
Hi, yes it works. Obviously I posted a camoufled binddn, basedn, etc...
I think you should also try the command with -ZZ argument to test if TLS initialization isn't getting in your way. Also please check that /etc/pki/tls/certs contains hashes (symlinks) of certificates you wish to use.
By executing your ldapsearch I obtain this: [cut] # search result search: 2 result: 0 Success
# numResponses: 164 # numEntries: 163
I already checked by tcpdump-ing the dialog between sssd and the ldap server and I saw only one ldapsearch executed, and this was simply against the rootDSE. I expected to see another one against my user db / basedn.
The only way that (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0010): Authentication mechanism not Supported by server is possible is if we get ENOTSUP back from the connection attempt. This can only happen if:
if (state->do_auth && sasl_mech && state->use_rootdse) { if (!sdap_is_sasl_mech_supported(state->sh, sasl_mech)) { tevent_req_error(req, ENOTSUP); return; } }
So that sounds to me like the list of supportedSASLMechanisms in the RootDSE is wrong.
Marco, please try this:
ldapsearch -H ldap://ldap.dont.mind.it -x -b '' -s base \ supportedSASLMechanisms
And tell us what it says. If that option returns nothing, I think that's probably a misconfiguration on the server (such as not having this attribute be readable by anonymous users). That said, we should probably assume by default that SASL/SIMPLE is always supported, even if the server is being stupid.
On Tue, Feb 7, 2012 at 2:41 PM, Stephen Gallagher sgallagh@redhat.comwrote:
On Tue, 2012-02-07 at 14:32 +0100, Jan Zelený wrote:
On Tue, Feb 7, 2012 at 2:10 PM, Stephen Gallagher
sgallagh@redhat.comwrote:
On Tue, 2012-02-07 at 14:04 +0100, Marco Pizzoli wrote:
Hi guys, Again I need your help... I'm using and I configured a domain/my_ldap. During the startup I see these logs:
[cut] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0100): Trying to resolve service
'LDAP'
(Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it'
is
'neutral' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout
set to
5 seconds (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_is_address] (0x4000): [ldap01.dont.mind.it] does not look like an IP address (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_gethostbyname_step] (0x2000): Querying files (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A
record
of 'ldap01.dont.mind.it' in files (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [set_server_common_status] (0x0100): Marking server 'ldap01.dont.mind.it' as 'resolving name' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [set_server_common_status] (0x0100): Marking server 'ldap01.dont.mind.it' as 'name resolved' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_resolve_server_done] (0x0100): Found address for server ldap01.dont.mind.it: [192.168.146.128] TTL 7200 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldap://ldap01.dont.mind.it:389' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] (0x4000): Using file descriptor [24] for LDAP connection. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://ldap01.dont.mind.it:389/??base] with fd [24]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]]
[sdap_get_rootdse_send]
(0x4000): Getting rootdse (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called,
msgid =
1 (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]]
[sdap_process_result]
(0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]]
[sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_entry] (0x4000): OriginalDN: []. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]]
[sdap_process_result]
(0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]]
[sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]]
[sdap_get_rootdse_done]
(0x4000): Got rootdse (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_naming_context] (0x0200): Using value from [namingContexts] as naming context. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]]
[sdap_set_search_base]
(0x0100): Setting option [ldap_sudo_search_base] to [dc=dont,dc=mind.it]. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_search_base] (0x0100): Search base added: [SUDO][dc=dont.mind.it][SUBTREE][] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_server_opts_from_rootdse] (0x0200): No known USN scheme
is
supported by this server! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_server_opts_from_rootdse] (0x0200): Will use modification timestamp as usn! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'ldap01.dont.mind.it' as 'not working' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]]
[sdap_handle_release]
(0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[(nil)], ldap[0x7f6ec4b579c0], destructor_lock[0], release_memory[0] (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [remove_connection_callback] (0x4000): Successfully removed
connection
callback. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0010): Authentication mechanism not Supported by server (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x4000): attempting failover retry on
op #1
(Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0100): Trying to resolve service
'LDAP'
(Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] (0x1000): Status of server 'ldap01.dont.mind.it' is 'name
resolved'
(Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it'
is
'not working' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_resolve_service_send] (0x0020): No available servers for
service
'LDAP' (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0020): Failed to connect, going
offline
(5 [Input/output error]) (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_mark_offline] (0x2000): Going offline! (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_run_offline_cb] (0x0080): Going offline. Running callbacks. (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x4000): notify offline to op #1 [cut]
My LDAP server is OpenLDAP. and I have configured the tls part.
[root@fedora16 ~]# netstat -ntlp |grep slapd tcp 0 0 0.0.0.0:636 0.0.0.0:* LISTEN 2951/slapd tcp 0 0 0.0.0.0:389 0.0.0.0:* LISTEN 2951/slapd tcp 0 0 :::636 :::* LISTEN 2951/slapd tcp 0 0 :::389 :::* LISTEN 2951/slapd
This is the interesting part of my domain/my_ldap section of
sssd.conf
[domain/my_ldap] description = LDAP Users domain min_id = 7000 max_id = 8000 timeout = 10 enumerate = TRUE entry_cache_timeout = 5400 cache_credentials = TRUE account_cache_expiration = 0 id_provider = ldap use_fully_qualified_names = FALSE auth_provider = ldap access_provider = permit chpass_provider = ldap lookup_family_order = ipv4_first dns_resolver_timeout = 5 #dns_discovery_domain = #override_gid = case_sensitive = True
ldap_uri = ldap://ldap01.dont.mind.it:389 ldap_chpass_uri = ldap://ldap01.dont.mind.it:389 ldap_search_base = dc=dont,dc=mind.it?sub?(objectClass=inetOrgPerson)http://mind.it?sub?%28objectClass=inetOrgPerson%29
%28objectClass=inetOrgPerson%29> ldap_schema = rfc2307bis ldap_default_bind_dn = cn=mydn,dc=dont,dc=mind.it ldap_default_authtok_type = pippo #ldap_default_authtok ldap_user_object_class = posixAccount ldap_user_name = uid ldap_user_uid_number = uidNumber ldap_user_gid_number = gidNumber ldap_user_gecos = gecos ldap_user_home_directory = homeDirectory ldap_user_shell = loginShell ldap_user_uuid = entryUUID ldap_user_modify_timestamp = modifyTimestamp ldap_user_shadow_last_change = shadowLastChange ldap_user_shadow_min = shadowMin
#### INIZIO - SSL/TLS #### # # Imposto la richiesta e la validazione del certificato ldap_tls_reqcert = demand # #ldap_tls_cacert = ldap_tls_cacertdir = /etc/pki/tls/certs #ldap_tls_cert = #ldap_tls_key = #ldap_tls_cipher_suite = ldap_id_use_start_tls = false #### FINE - SSL/TLS ####
Could you help me in understanding what is the cause of the backend discard?
Can you tell us if it works if you do:
ldapsearch -H ldap://ldap.dont.mind.it -x -w \ -D cn=mydn,dc=dont,dc=mind.it -b dc=dont,dc=mind.it \ objectClass=inetOrgPerson
Hi, yes it works. Obviously I posted a camoufled binddn, basedn, etc...
I think you should also try the command with -ZZ argument to test if TLS initialization isn't getting in your way. Also please check that /etc/pki/tls/certs contains hashes (symlinks) of certificates you wish
to use.
By executing your ldapsearch I obtain this: [cut] # search result search: 2 result: 0 Success
# numResponses: 164 # numEntries: 163
I already checked by tcpdump-ing the dialog between sssd and the ldap server and I saw only one ldapsearch executed, and this was simply
against
the rootDSE. I expected to see another one against my user db / basedn.
The only way that (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0010): Authentication mechanism not Supported by server is possible is if we get ENOTSUP back from the connection attempt. This can only happen if:
if (state->do_auth && sasl_mech && state->use_rootdse) { if (!sdap_is_sasl_mech_supported(state->sh, sasl_mech)) { tevent_req_error(req, ENOTSUP); return; } }
So that sounds to me like the list of supportedSASLMechanisms in the RootDSE is wrong.
Marco, please try this:
ldapsearch -H ldap://ldap.dont.mind.it -x -b '' -s base \ supportedSASLMechanisms
And tell us what it says. If that option returns nothing, I think that's probably a misconfiguration on the server (such as not having this attribute be readable by anonymous users). That said, we should probably assume by default that SASL/SIMPLE is always supported, even if the server is being stupid.
Here it is:
[root@fedora16 ~]# ldapsearch -v -x -h 127.0.0.1 -b "" -s base -D "cn=Manager,dc=dont,dc=mind.it" -wmy_pw supportedSASLMechanisms ldap_initialize( ldap://127.0.0.1 ) filter: (objectclass=*) requesting: supportedSASLMechanisms # extended LDIF # # LDAPv3 # base <> with scope baseObject # filter: (objectclass=*) # requesting: supportedSASLMechanisms #
# dn: supportedSASLMechanisms: GSSAPI
# search result search: 2 result: 0 Success
# numResponses: 2 # numEntries: 1
Thanks Marco
On Tue, 2012-02-07 at 16:12 +0100, Marco Pizzoli wrote:
On Tue, Feb 7, 2012 at 2:41 PM, Stephen Gallagher sgallagh@redhat.com wrote: On Tue, 2012-02-07 at 14:32 +0100, Jan Zelený wrote: > > On Tue, Feb 7, 2012 at 2:10 PM, Stephen Gallagher > sgallagh@redhat.comwrote: > > > On Tue, 2012-02-07 at 14:04 +0100, Marco Pizzoli wrote: > > > > Hi guys, > > > > Again I need your help... I'm using and I configured a > > > > domain/my_ldap. During the startup I see these logs: > > > > > > > > [cut] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_op_connect_step] (0x4000): beginning to connect > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] > > > > (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not > > > > resolved' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] > > > > (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is > > > > 'neutral' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to > > > > 5 seconds > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] > > > > (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not > > > > resolved' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_is_address] > > > > (0x4000): [ldap01.dont.mind.it] does not look like an IP address > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [resolv_gethostbyname_step] (0x2000): Querying files > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record > > > > of 'ldap01.dont.mind.it' in files > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [set_server_common_status] (0x0100): Marking server > > > > 'ldap01.dont.mind.it' as 'resolving name' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [set_server_common_status] (0x0100): Marking server > > > > 'ldap01.dont.mind.it' as 'name resolved' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [be_resolve_server_done] (0x0100): Found address for server > > > > ldap01.dont.mind.it: [192.168.146.128] TTL 7200 > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_uri_callback] > > > > (0x0400): Constructed uri 'ldap://ldap01.dont.mind.it:389' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] > > > > (0x4000): Using file descriptor [24] for LDAP connection. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] > > > > (0x0400): Setting 6 seconds timeout for connecting > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to > > > > [ldap://ldap01.dont.mind.it:389/??base] with fd [24]. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_send] > > > > (0x4000): Getting rootdse > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with > > > > [(objectclass=*)][]. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [namingContexts] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [supportedControl] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [supportedExtension] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [supportedFeatures] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [supportedLDAPVersion] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [supportedSASLMechanisms] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [defaultNamingContext] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [highestCommittedUSN] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = > > > > 1 > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] > > > > (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], > > > > ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] > > > > (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_entry] > > > > (0x4000): OriginalDN: []. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] > > > > (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], > > > > ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] > > > > (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no > > > > errmsg set > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_done] > > > > (0x4000): Got rootdse > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_naming_context] > > > > (0x0200): Using value from [namingContexts] as naming context. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_set_search_base] > > > > (0x0100): Setting option [ldap_sudo_search_base] to > > > > [dc=dont,dc=mind.it]. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_parse_search_base] (0x0100): Search base added: > > > > [SUDO][dc=dont.mind.it][SUBTREE][] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_server_opts_from_rootdse] (0x0200): No known USN scheme is > > > > supported by this server! > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_server_opts_from_rootdse] (0x0200): Will use modification > > > > timestamp as usn! > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_set_port_status] > > > > (0x0100): Marking port 389 of server 'ldap01.dont.mind.it' as 'not > > > > working' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_handle_release] > > > > (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[(nil)], > > > > ldap[0x7f6ec4b579c0], destructor_lock[0], release_memory[0] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [remove_connection_callback] (0x4000): Successfully removed connection > > > > callback. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_op_connect_done] (0x0010): Authentication mechanism not > > > > Supported by server > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_op_connect_done] (0x4000): attempting failover retry on op #1 > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_op_connect_step] (0x4000): beginning to connect > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] > > > > (0x1000): Status of server 'ldap01.dont.mind.it' is 'name resolved' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] > > > > (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is > > > > 'not working' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [fo_resolve_service_send] (0x0020): No available servers for service > > > > 'LDAP' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_release_conn_data] (0x4000): releasing unused connection > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_op_connect_done] (0x0020): Failed to connect, going offline > > > > (5 [Input/output error]) > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_mark_offline] > > > > (0x2000): Going offline! > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_run_offline_cb] > > > > (0x0080): Going offline. Running callbacks. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_op_connect_done] (0x4000): notify offline to op #1 > > > > [cut] > > > > > > > > My LDAP server is OpenLDAP. and I have configured the tls part. > > > > > > > > [root@fedora16 ~]# netstat -ntlp |grep slapd > > > > tcp 0 0 0.0.0.0:636 0.0.0.0:* > > > > LISTEN 2951/slapd > > > > tcp 0 0 0.0.0.0:389 0.0.0.0:* > > > > LISTEN 2951/slapd > > > > tcp 0 0 :::636 :::* > > > > LISTEN 2951/slapd > > > > tcp 0 0 :::389 :::* > > > > LISTEN 2951/slapd > > > > > > > > This is the interesting part of my domain/my_ldap section of sssd.conf > > > > > > > > [domain/my_ldap] > > > > description = LDAP Users domain > > > > min_id = 7000 > > > > max_id = 8000 > > > > timeout = 10 > > > > enumerate = TRUE > > > > entry_cache_timeout = 5400 > > > > cache_credentials = TRUE > > > > account_cache_expiration = 0 > > > > id_provider = ldap > > > > use_fully_qualified_names = FALSE > > > > auth_provider = ldap > > > > access_provider = permit > > > > chpass_provider = ldap > > > > lookup_family_order = ipv4_first > > > > dns_resolver_timeout = 5 > > > > #dns_discovery_domain = > > > > #override_gid = > > > > case_sensitive = True > > > > > > > > ldap_uri = ldap://ldap01.dont.mind.it:389 > > > > ldap_chpass_uri = ldap://ldap01.dont.mind.it:389 > > > > ldap_search_base = > > > > dc=dont,dc=mind.it?sub?(objectClass=inetOrgPerson)<http://mind.it?sub? > > > > %28objectClass=inetOrgPerson%29> ldap_schema = rfc2307bis > > > > ldap_default_bind_dn = cn=mydn,dc=dont,dc=mind.it > > > > ldap_default_authtok_type = pippo > > > > #ldap_default_authtok > > > > ldap_user_object_class = posixAccount > > > > ldap_user_name = uid > > > > ldap_user_uid_number = uidNumber > > > > ldap_user_gid_number = gidNumber > > > > ldap_user_gecos = gecos > > > > ldap_user_home_directory = homeDirectory > > > > ldap_user_shell = loginShell > > > > ldap_user_uuid = entryUUID > > > > ldap_user_modify_timestamp = modifyTimestamp > > > > ldap_user_shadow_last_change = shadowLastChange > > > > ldap_user_shadow_min = shadowMin > > > > > > > > #### INIZIO - SSL/TLS #### > > > > # > > > > # Imposto la richiesta e la validazione del certificato > > > > ldap_tls_reqcert = demand > > > > # > > > > #ldap_tls_cacert = > > > > ldap_tls_cacertdir = /etc/pki/tls/certs > > > > #ldap_tls_cert = > > > > #ldap_tls_key = > > > > #ldap_tls_cipher_suite = > > > > ldap_id_use_start_tls = false > > > > #### FINE - SSL/TLS #### > > > > > > > > Could you help me in understanding what is the cause of the backend > > > > discard? > > > > > > Can you tell us if it works if you do: > > > > > > ldapsearch -H ldap://ldap.dont.mind.it -x -w \ > > > -D cn=mydn,dc=dont,dc=mind.it -b dc=dont,dc=mind.it \ > > > objectClass=inetOrgPerson > > > > Hi, yes it works. Obviously I posted a camoufled binddn, basedn, etc... > > I think you should also try the command with -ZZ argument to test if TLS > initialization isn't getting in your way. Also please check that > /etc/pki/tls/certs contains hashes (symlinks) of certificates you wish to use. > > > > > By executing your ldapsearch I obtain this: > > [cut] > > # search result > > search: 2 > > result: 0 Success > > > > # numResponses: 164 > > # numEntries: 163 > > > > I already checked by tcpdump-ing the dialog between sssd and the ldap > > server and I saw only one ldapsearch executed, and this was simply against > > the rootDSE. I expected to see another one against my user db / basedn.
The only way that (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0010): Authentication mechanism not Supported by server is possible is if we get ENOTSUP back from the connection attempt. This can only happen if: if (state->do_auth && sasl_mech && state->use_rootdse) { if (!sdap_is_sasl_mech_supported(state->sh, sasl_mech)) { tevent_req_error(req, ENOTSUP); return; } } So that sounds to me like the list of supportedSASLMechanisms in the RootDSE is wrong. Marco, please try this: ldapsearch -H ldap://ldap.dont.mind.it -x -b '' -s base \ supportedSASLMechanisms And tell us what it says. If that option returns nothing, I think that's probably a misconfiguration on the server (such as not having this attribute be readable by anonymous users). That said, we should probably assume by default that SASL/SIMPLE is always supported, even if the server is being stupid.
Here it is:
[root@fedora16 ~]# ldapsearch -v -x -h 127.0.0.1 -b "" -s base -D "cn=Manager,dc=dont,dc=mind.it" -wmy_pw supportedSASLMechanisms ldap_initialize( ldap://127.0.0.1 ) filter: (objectclass=*) requesting: supportedSASLMechanisms # extended LDIF # # LDAPv3 # base <> with scope baseObject # filter: (objectclass=*) # requesting: supportedSASLMechanisms #
# dn: supportedSASLMechanisms: GSSAPI
# search result search: 2 result: 0 Success
# numResponses: 2 # numEntries: 1
According to that, your LDAP server doesn't support any authentication except GSSAPI (probably Kerberos). Obviously ldapsearch still works, so it looks to me like the LDAP server isn't properly reporting what it reports.
Please open a bug. SSSD should be assuming that we always support SIMPLE.
On Tue, Feb 7, 2012 at 4:19 PM, Stephen Gallagher sgallagh@redhat.comwrote:
On Tue, 2012-02-07 at 16:12 +0100, Marco Pizzoli wrote:
On Tue, Feb 7, 2012 at 2:41 PM, Stephen Gallagher sgallagh@redhat.com wrote: On Tue, 2012-02-07 at 14:32 +0100, Jan Zelený wrote: > > On Tue, Feb 7, 2012 at 2:10 PM, Stephen Gallagher > sgallagh@redhat.comwrote: > > > On Tue, 2012-02-07 at 14:04 +0100, Marco Pizzoli wrote: > > > > Hi guys, > > > > Again I need your help... I'm using and I configured a > > > > domain/my_ldap. During the startup I see these logs: > > > > > > > > [cut] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_op_connect_step] (0x4000): beginning to connect > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] > > > > (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not > > > > resolved' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] > > > > (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is > > > > 'neutral' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to > > > > 5 seconds > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] > > > > (0x1000): Status of server 'ldap01.dont.mind.it' is 'name not > > > > resolved' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [resolv_is_address] > > > > (0x4000): [ldap01.dont.mind.it] does not look like an IP address > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [resolv_gethostbyname_step] (0x2000): Querying files > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record > > > > of 'ldap01.dont.mind.it' in files > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [set_server_common_status] (0x0100): Marking server > > > > 'ldap01.dont.mind.it' as 'resolving name' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [set_server_common_status] (0x0100): Marking server > > > > 'ldap01.dont.mind.it' as 'name resolved' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [be_resolve_server_done] (0x0100): Found address for server > > > > ldap01.dont.mind.it: [192.168.146.128] TTL 7200 > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_uri_callback] > > > > (0x0400): Constructed uri 'ldap://ldap01.dont.mind.it:389' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] > > > > (0x4000): Using file descriptor [24] for LDAP connection. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sss_ldap_init_send] > > > > (0x0400): Setting 6 seconds timeout for connecting > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to > > > > [ldap://ldap01.dont.mind.it:389/??base] with fd [24]. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_send] > > > > (0x4000): Getting rootdse > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with > > > > [(objectclass=*)][]. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [namingContexts] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [supportedControl] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [supportedExtension] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [supportedFeatures] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [supportedLDAPVersion] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [supportedSASLMechanisms] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [defaultNamingContext] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: > > > > [highestCommittedUSN] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = > > > > 1 > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] > > > > (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], > > > > ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] > > > > (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_parse_entry] > > > > (0x4000): OriginalDN: []. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_result] > > > > (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], > > > > ops[0x7f6ec4b6a610], ldap[0x7f6ec4b579c0] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_process_message] > > > > (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no > > > > errmsg set > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_get_rootdse_done] > > > > (0x4000): Got rootdse > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_naming_context] > > > > (0x0200): Using value from [namingContexts] as naming context. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_set_search_base] > > > > (0x0100): Setting option [ldap_sudo_search_base] to > > > > [dc=dont,dc=mind.it]. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_parse_search_base] (0x0100): Search base added: > > > > [SUDO][dc=dont.mind.it][SUBTREE][] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_server_opts_from_rootdse] (0x0200): No known USN scheme is > > > > supported by this server! > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_get_server_opts_from_rootdse] (0x0200): Will use modification > > > > timestamp as usn! > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [fo_set_port_status] > > > > (0x0100): Marking port 389 of server 'ldap01.dont.mind.it' as 'not > > > > working' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_handle_release] > > > > (0x2000): Trace: sh[0x7f6ec4b54440], connected[1], ops[(nil)], > > > > ldap[0x7f6ec4b579c0], destructor_lock[0], release_memory[0] > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [remove_connection_callback] (0x4000): Successfully removed connection > > > > callback. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_op_connect_done] (0x0010): Authentication mechanism not > > > > Supported by server > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_op_connect_done] (0x4000): attempting failover retry on op #1 > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_op_connect_step] (0x4000): beginning to connect > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_server_status] > > > > (0x1000): Status of server 'ldap01.dont.mind.it' is 'name resolved' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [get_port_status] > > > > (0x1000): Port status of port 389 for server 'ldap01.dont.mind.it' is > > > > 'not working' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [fo_resolve_service_send] (0x0020): No available servers for service > > > > 'LDAP' > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_release_conn_data] (0x4000): releasing unused connection > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_op_connect_done] (0x0020): Failed to connect, going offline > > > > (5 [Input/output error]) > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_mark_offline] > > > > (0x2000): Going offline! > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [be_run_offline_cb] > > > > (0x0080): Going offline. Running callbacks. > > > > (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] > > > > [sdap_id_op_connect_done] (0x4000): notify offline to op #1 > > > > [cut] > > > > > > > > My LDAP server is OpenLDAP. and I have configured the tls part. > > > > > > > > [root@fedora16 ~]# netstat -ntlp |grep slapd > > > > tcp 0 0 0.0.0.0:636 0.0.0.0:* > > > > LISTEN 2951/slapd > > > > tcp 0 0 0.0.0.0:389 0.0.0.0:* > > > > LISTEN 2951/slapd > > > > tcp 0 0 :::636 :::* > > > > LISTEN 2951/slapd > > > > tcp 0 0 :::389 :::* > > > > LISTEN 2951/slapd > > > > > > > > This is the interesting part of my domain/my_ldap section of sssd.conf > > > > > > > > [domain/my_ldap] > > > > description = LDAP Users domain > > > > min_id = 7000 > > > > max_id = 8000 > > > > timeout = 10 > > > > enumerate = TRUE > > > > entry_cache_timeout = 5400 > > > > cache_credentials = TRUE > > > > account_cache_expiration = 0 > > > > id_provider = ldap > > > > use_fully_qualified_names = FALSE > > > > auth_provider = ldap > > > > access_provider = permit > > > > chpass_provider = ldap > > > > lookup_family_order = ipv4_first > > > > dns_resolver_timeout = 5 > > > > #dns_discovery_domain = > > > > #override_gid = > > > > case_sensitive = True > > > > > > > > ldap_uri = ldap://ldap01.dont.mind.it:389 > > > > ldap_chpass_uri = ldap://ldap01.dont.mind.it:389 > > > > ldap_search_base = > > > > dc=dont,dc=mind.it?sub?(objectClass=inetOrgPerson)http://mind.it?sub?%28objectClass=inetOrgPerson%29
> > > > %28objectClass=inetOrgPerson%29> ldap_schema = rfc2307bis > > > > ldap_default_bind_dn = cn=mydn,dc=dont,dc=mind.it > > > > ldap_default_authtok_type = pippo > > > > #ldap_default_authtok > > > > ldap_user_object_class = posixAccount > > > > ldap_user_name = uid > > > > ldap_user_uid_number = uidNumber > > > > ldap_user_gid_number = gidNumber > > > > ldap_user_gecos = gecos > > > > ldap_user_home_directory = homeDirectory > > > > ldap_user_shell = loginShell > > > > ldap_user_uuid = entryUUID > > > > ldap_user_modify_timestamp = modifyTimestamp > > > > ldap_user_shadow_last_change = shadowLastChange > > > > ldap_user_shadow_min = shadowMin > > > > > > > > #### INIZIO - SSL/TLS #### > > > > # > > > > # Imposto la richiesta e la validazione del certificato > > > > ldap_tls_reqcert = demand > > > > # > > > > #ldap_tls_cacert = > > > > ldap_tls_cacertdir = /etc/pki/tls/certs > > > > #ldap_tls_cert = > > > > #ldap_tls_key = > > > > #ldap_tls_cipher_suite = > > > > ldap_id_use_start_tls = false > > > > #### FINE - SSL/TLS #### > > > > > > > > Could you help me in understanding what is the cause of the backend > > > > discard? > > > > > > Can you tell us if it works if you do: > > > > > > ldapsearch -H ldap://ldap.dont.mind.it -x -w \ > > > -D cn=mydn,dc=dont,dc=mind.it -b dc=dont,dc=mind.it \ > > > objectClass=inetOrgPerson > > > > Hi, yes it works. Obviously I posted a camoufled binddn, basedn, etc... > > I think you should also try the command with -ZZ argument to test if TLS > initialization isn't getting in your way. Also please check that > /etc/pki/tls/certs contains hashes (symlinks) of certificates you wish to use. > > > > > By executing your ldapsearch I obtain this: > > [cut] > > # search result > > search: 2 > > result: 0 Success > > > > # numResponses: 164 > > # numEntries: 163 > > > > I already checked by tcpdump-ing the dialog between sssd and the ldap > > server and I saw only one ldapsearch executed, and this was simply against > > the rootDSE. I expected to see another one against my user db / basedn. The only way that (Tue Feb 7 13:44:04 2012) [sssd[be[my_ldap]]] [sdap_id_op_connect_done] (0x0010): Authentication mechanism not Supported by server is possible is if we get ENOTSUP back from the connection attempt. This can only happen if: if (state->do_auth && sasl_mech && state->use_rootdse) { if (!sdap_is_sasl_mech_supported(state->sh, sasl_mech)) { tevent_req_error(req, ENOTSUP); return; } } So that sounds to me like the list of supportedSASLMechanisms in the RootDSE is wrong. Marco, please try this: ldapsearch -H ldap://ldap.dont.mind.it -x -b '' -s base \ supportedSASLMechanisms And tell us what it says. If that option returns nothing, I think that's probably a misconfiguration on the server (such as not having this attribute be readable by anonymous users). That said, we should probably assume by default that SASL/SIMPLE is always supported, even if the server is being stupid.
Here it is:
[root@fedora16 ~]# ldapsearch -v -x -h 127.0.0.1 -b "" -s base -D "cn=Manager,dc=dont,dc=mind.it" -wmy_pw supportedSASLMechanisms ldap_initialize( ldap://127.0.0.1 ) filter: (objectclass=*) requesting: supportedSASLMechanisms # extended LDIF # # LDAPv3 # base <> with scope baseObject # filter: (objectclass=*) # requesting: supportedSASLMechanisms #
# dn: supportedSASLMechanisms: GSSAPI
# search result search: 2 result: 0 Success
# numResponses: 2 # numEntries: 1
According to that, your LDAP server doesn't support any authentication except GSSAPI (probably Kerberos). Obviously ldapsearch still works, so it looks to me like the LDAP server isn't properly reporting what it reports.
Please open a bug. SSSD should be assuming that we always support SIMPLE.
Done. https://fedorahosted.org/sssd/ticket/1180
Please, could you tell me if this problem will be targeted for 1.7.x or 1.8 release?
Thanks
On Tue, 2012-02-07 at 17:28 +0100, Marco Pizzoli wrote:
According to that, your LDAP server doesn't support any authentication except GSSAPI (probably Kerberos). Obviously ldapsearch still works, so it looks to me like the LDAP server isn't properly reporting what it reports. Please open a bug. SSSD should be assuming that we always support SIMPLE.
Done. https://fedorahosted.org/sssd/ticket/1180
Please, could you tell me if this problem will be targeted for 1.7.x or 1.8 release?
Actually, on further investigation, this shouldn't be an issue. Can you confirm that you are NOT setting ldap_sasl_mech in your sssd.conf? It's not listed in your first email, but did you maybe leave it out?
The code that checks for this should be skipped if ldap_sasl_mech is unset.
Would you mind checking your startup logs at level 6 to see what value is being reported for ldap_sasl_mech?
On Tue, Feb 7, 2012 at 5:38 PM, Stephen Gallagher sgallagh@redhat.comwrote:
On Tue, 2012-02-07 at 17:28 +0100, Marco Pizzoli wrote:
According to that, your LDAP server doesn't support any authentication except GSSAPI (probably Kerberos). Obviously ldapsearch still works, so it looks to me like the LDAP server isn't properly reporting what it reports. Please open a bug. SSSD should be assuming that we always support SIMPLE.
Done. https://fedorahosted.org/sssd/ticket/1180
Please, could you tell me if this problem will be targeted for 1.7.x or 1.8 release?
Actually, on further investigation, this shouldn't be an issue. Can you confirm that you are NOT setting ldap_sasl_mech in your sssd.conf? It's not listed in your first email, but did you maybe leave it out?
It seems you found my fault :-( I surely overlooked the meaning of the word "none" on the man page. This is it: ldap_sasl_mech = none
The code that checks for this should be skipped if ldap_sasl_mech is unset.
Would you mind checking your startup logs at level 6 to see what value is being reported for ldap_sasl_mech?
Done. As already reported: ldap_sasl_mech = none
I commented that directive, restarted sssd and now I see it working and obtaining my groups from the LDAP server. I still don't see my users and groups, but this is another story.
Thanks a lot and apologize for the noise. Marco
On Tue, 2012-02-07 at 18:06 +0100, Marco Pizzoli wrote:
On Tue, Feb 7, 2012 at 5:38 PM, Stephen Gallagher sgallagh@redhat.com wrote: On Tue, 2012-02-07 at 17:28 +0100, Marco Pizzoli wrote: > > > According to that, your LDAP server doesn't support any > authentication > except GSSAPI (probably Kerberos). Obviously ldapsearch still > works, so > it looks to me like the LDAP server isn't properly reporting > what it > reports. > > Please open a bug. SSSD should be assuming that we always > support > SIMPLE. > > Done. https://fedorahosted.org/sssd/ticket/1180 > > Please, could you tell me if this problem will be targeted for 1.7.x > or 1.8 release?
Actually, on further investigation, this shouldn't be an issue. Can you confirm that you are NOT setting ldap_sasl_mech in your sssd.conf? It's not listed in your first email, but did you maybe leave it out?
It seems you found my fault :-( I surely overlooked the meaning of the word "none" on the man page. This is it: ldap_sasl_mech = none
The code that checks for this should be skipped if ldap_sasl_mech is unset. Would you mind checking your startup logs at level 6 to see what value is being reported for ldap_sasl_mech?
Done. As already reported: ldap_sasl_mech = none
I commented that directive, restarted sssd and now I see it working and obtaining my groups from the LDAP server. I still don't see my users and groups, but this is another story.
Thanks a lot and apologize for the noise. Marco
Ah, yeah. That should be "not set" rather than "none".
We'll have to fix that in 1.9 (we're past string freeze for 1.8)
On Tue, Feb 7, 2012 at 6:10 PM, Stephen Gallagher sgallagh@redhat.comwrote:
On Tue, 2012-02-07 at 18:06 +0100, Marco Pizzoli wrote:
On Tue, Feb 7, 2012 at 5:38 PM, Stephen Gallagher sgallagh@redhat.com wrote: On Tue, 2012-02-07 at 17:28 +0100, Marco Pizzoli wrote: > > > According to that, your LDAP server doesn't support any > authentication > except GSSAPI (probably Kerberos). Obviously ldapsearch still > works, so > it looks to me like the LDAP server isn't properly reporting > what it > reports. > > Please open a bug. SSSD should be assuming that we always > support > SIMPLE. > > Done. https://fedorahosted.org/sssd/ticket/1180 > > Please, could you tell me if this problem will be targeted for 1.7.x > or 1.8 release?
Actually, on further investigation, this shouldn't be an issue. Can you confirm that you are NOT setting ldap_sasl_mech in your sssd.conf? It's not listed in your first email, but did you maybe leave it out?
It seems you found my fault :-( I surely overlooked the meaning of the word "none" on the man page. This is it: ldap_sasl_mech = none
The code that checks for this should be skipped if ldap_sasl_mech is unset. Would you mind checking your startup logs at level 6 to see what value is being reported for ldap_sasl_mech?
Done. As already reported: ldap_sasl_mech = none
I commented that directive, restarted sssd and now I see it working and obtaining my groups from the LDAP server. I still don't see my users and groups, but this is another story.
Thanks a lot and apologize for the noise. Marco
Ah, yeah. That should be "not set" rather than "none".
Please let me try to write this patch as I have already taught :-) I'm going to do it in the weekend, I promise!
We'll have to fix that in 1.9 (we're past string freeze for 1.8)
I understand. Marco
sssd-devel@lists.fedorahosted.org