Hi guys,
I'm currently not able to get sssd working in connecting to an AD server as a pure LDAPS server.
 
I'm succeeding in connecting with a simple bind, but eventually I can't get sssd downloading any data. It ends with a
 Search result: Operations error(1), 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
 
By using ldapsearch (pointing to the same ldaps url) I can execute the same search obtaining (correctly) 1 user.
Honestly, I don't know what could be the problem... Any hint on a particular configuration directive to check?
 
Full log following.
I'm using sssd-1.8.0-32.el6.x86_64 on RHEL6.3
 
Thanks in advance
Marco
------------------------------------------------------------------------------------
 
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [server_setup] (0x0080): CONFDB: /var/lib/sss/db/config.ldb
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [recreate_ares_channel] (0x0100): Initializing new c-ares channel
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [resolv_get_family_order] (0x1000): Lookup order: ipv4_first
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [fo_context_init] (0x0080): Created new fail over context, retry timeout is 30
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sysdb_domain_init_internal] (0x0200): DB File for TESTpippo.local: /var/lib/sss/db/cache_TESTpippo.local.ldb
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x79c040
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x79d4a0
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Destroying timer event 0x79d4a0 "ltdb_timeout"
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Ending timer event 0x79c040 "ltdb_callback"
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): trying to load memberof from /usr/lib64/ldb/memberof.so
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x0400): asq: Unable to register control with rootdse!
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x79c710
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x79c040
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Destroying timer event 0x79c040 "ltdb_timeout"
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Ending timer event 0x79c710 "ltdb_callback"
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x79b890
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x79cad0
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Destroying timer event 0x79cad0 "ltdb_timeout"
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Ending timer event 0x79b890 "ltdb_callback"
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_init_connection] (0x0200): Adding connection 7B1BF0
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_add_watch] (0x2000): 0x7afa50/0x7afff0 (21), -/W (enabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7afa50/0x7b1070 (21), R/- (disabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [monitor_common_send_id] (0x0100): Sending ID: (%BE_TESTpippo.local,1)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_add_timeout] (0x2000): 0x7b0980
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7afa50/0x7b1070 (21), R/- (enabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7afa50/0x7afff0 (21), -/W (disabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [create_socket_symlink] (0x1000): Symlinking the dbus path /var/lib/sss/pipes/private/sbus-dp_TESTpippo.local.11367 to a link /var/lib/sss/pipes/private/sbus-dp_TESTpippo.local
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_new_server] (0x0080): D-BUS Server listening on unix:path=/var/lib/sss/pipes/private/sbus-dp_TESTpippo.local.11367,guid=2ae7a8dae11a4c18d135b45f0036ec0b
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_add_watch] (0x2000): 0x7b2710/0x7b28b0 (22), R/- (enabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [load_backend_module] (0x1000): Loading backend [ldap] with path [/usr/lib64/sssd/libsss_ldap.so].
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_uri has value ldaps://miaomiao.testpippo.local,ldaps://wofwof.testpippo.local
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_search_base has value DC=testpippo,DC=local
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_default_bind_dn has value CN=baubau,OU=Service Accounts,DC=testpippo,DC=local
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_default_authtok_type has value password
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_default_authtok has no binary value.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_search_timeout has value 6
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_network_timeout has value 6
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_opt_timeout has value 6
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_tls_reqcert has value never
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_user_search_base has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_user_search_scope has value sub
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_user_search_filter has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_group_search_base has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_group_search_scope has value sub
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_group_search_filter has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_service_search_base has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_sudo_search_base has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_sudo_refresh_enabled is FALSE
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_sudo_refresh_timeout has value 300
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_autofs_search_base has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_schema has value rfc2307bis
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_offline_timeout has value 60
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_force_upper_case_realm is TRUE
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_enumeration_refresh_timeout has value 300
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_purge_cache_timeout has value 10800
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_tls_cacert has value /opt/openldap/TLS/mycorp_Test01_CA.crt
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_tls_cacertdir has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_tls_cert has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_tls_key has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_tls_cipher_suite has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_id_use_start_tls is FALSE
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_sasl_mech has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_sasl_authid has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_sasl_realm has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_sasl_minssf has value -1
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_krb5_keytab has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_krb5_init_creds is TRUE
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option krb5_server has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option krb5_realm has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option krb5_canonicalize is TRUE
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_pwd_policy has value none
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_referrals is FALSE
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option account_cache_expiration has value 0
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_dns_service_name has value ldap
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_krb5_ticket_lifetime has value 86400
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_access_filter has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_netgroup_search_base has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_group_nesting_level has value 0
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_deref has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_account_expire_policy has value ad
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_access_order has value expire
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_chpass_uri has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_chpass_dns_service_name has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_chpass_update_last_change is FALSE
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_enumeration_search_timeout has value 60
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_auth_disable_tls_never_use_in_production is FALSE
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_page_size has value 1000
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_deref_threshold has value 10
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_sasl_canonicalize is FALSE
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_connection_expire_timeout has value 900
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [dp_get_options] (0x0400): Option ldap_disable_paging is FALSE
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldap_get_options] (0x0400): Option ldap_user_search_base set to DC=testpippo,DC=local
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldap_get_options] (0x0400): Option ldap_group_search_base set to DC=testpippo,DC=local
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldap_get_options] (0x0400): Option ldap_netgroup_search_base set to DC=testpippo,DC=local
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldap_get_options] (0x0400): Option ldap_service_search_base set to DC=testpippo,DC=local
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [common_parse_search_base] (0x0100): Search base added: [DEFAULT][DC=testpippo,DC=local][SUBTREE][]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [common_parse_search_base] (0x0100): Search base added: [USER][DC=testpippo,DC=local][SUBTREE][]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [common_parse_search_base] (0x0100): Search base added: [GROUP][DC=testpippo,DC=local][SUBTREE][]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [common_parse_search_base] (0x0100): Search base added: [NETGROUP][DC=testpippo,DC=local][SUBTREE][]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [common_parse_search_base] (0x0100): Search base added: [SERVICE][DC=testpippo,DC=local][SUBTREE][]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_entry_usn has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_rootdse_last_usn has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_object_class has value user
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_name has value sAMAccountName
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_pwd has value userPassword
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_uid_number has value uidNumber
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_gid_number has value gidNumber
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_gecos has value displayName
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_home_directory has value unixHomeDirectory
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_shell has value loginShell
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_principal has value userPrincipalName
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_fullname has value cn
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_member_of has value memberOf
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_uuid has value nsUniqueId
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_modify_timestamp has value modifyTimestamp
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_entry_usn has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_shadow_last_change has value shadowLastChange
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_shadow_min has value shadowMin
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_shadow_max has value shadowMax
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_shadow_warning has value shadowWarning
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_shadow_inactive has value shadowInactive
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_shadow_expire has value shadowExpire
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_shadow_flag has value shadowFlag
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_krb_last_pwd_change has value krbLastPwdChange
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_krb_password_expiration has value krbPasswordExpiration
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_pwd_attribute has value pwdAttribute
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_authorized_service has value authorizedService
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_ad_account_expires has value accountExpires
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_ad_user_account_control has value userAccountControl
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_ns_account_lock has value nsAccountLock
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_authorized_host has value host
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_nds_login_disabled has value loginDisabled
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_nds_login_expiration_time has value loginExpirationTime
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_nds_login_allowed_time_map has value loginAllowedTimeMap
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_user_ssh_public_key has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_group_object_class has value group
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_group_name has value cn
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_group_pwd has value userPassword
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_group_gid_number has value gidNumber
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_group_member has value member
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_group_uuid has value nsUniqueId
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_group_modify_timestamp has value modifyTimestamp
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_group_entry_usn has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_netgroup_object_class has value nisNetgroup
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_netgroup_name has value cn
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_netgroup_member has value memberNisNetgroup
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_netgroup_triple has value nisNetgroupTriple
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_netgroup_uuid has value nsUniqueId
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_netgroup_modify_timestamp has value modifyTimestamp
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_service_object_class has value ipService
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_service_name has value cn
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_service_port has value ipServicePort
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_service_proto has value ipServiceProtocol
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_service_entry_usn has value (null)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [krb5_try_kdcip] (0x0100): No KDC found in configuration, trying legacy option
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sssm_ldap_id_init] (0x1000): Service name for discovery set to ldap
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [fo_new_service] (0x0080): Creating new service 'LDAP'
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_service_init] (0x0400): Added URI ldaps://miaomiao.testpippo.local
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [fo_add_server] (0x0080): Adding new server 'miaomiao.testpippo.local', to service 'LDAP'
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_service_init] (0x0400): Added URI ldaps://wofwof.testpippo.local
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [fo_add_server] (0x0080): Adding new server 'wofwof.testpippo.local', to service 'LDAP'
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x7ba4e0
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x7b7460
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Destroying timer event 0x7b7460 "ltdb_timeout"
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldb] (0x4000): tevent: Ending timer event 0x7ba4e0 "ltdb_callback"
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldap_id_enumerate_set_timer] (0x0400): Scheduling next enumeration at 1357114836.1801018
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [be_process_init] (0x2000): ID backend target successfully loaded from provider [ldap].
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sssm_ldap_id_init] (0x2000): Re-using sdap_id_ctx for this provider
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [be_process_init] (0x2000): AUTH backend target successfully loaded from provider [ldap].
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sssm_ldap_id_init] (0x2000): Re-using sdap_id_ctx for this provider
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [be_process_init] (0x2000): ACCESS backend target successfully loaded from provider [ldap].
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sssm_ldap_id_init] (0x2000): Re-using sdap_id_ctx for this provider
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sssm_ldap_chpass_init] (0x4000): ldap_chpass_uri and ldap_chpass_dns_service_name not set, using ldap_uri.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [be_process_init] (0x2000): CHPASS backend target successfully loaded from provider [ldap].
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [load_backend_module] (0x0200): no module name found in confdb, using [ldap].
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sssm_ldap_sudo_init] (0x0080): Sudo init handler called but SSSD is built without sudo support, ignoring
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [be_process_init] (0x2000): SUDO backend target successfully loaded from provider [ldap].
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [load_backend_module] (0x0200): no module name found in confdb, using [ldap].
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sssm_ldap_id_init] (0x2000): Re-using sdap_id_ctx for this provider
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_autofs_init] (0x2000): Initializing autofs LDAP back end
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [ldap_get_autofs_options] (0x0200): Option ldap_autofs_search_base set to DC=testpippo,DC=local
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [common_parse_search_base] (0x0100): Search base added: [AUTOFS][DC=testpippo,DC=local][SUBTREE][]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_autofs_map_object_class has value automountMap
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_autofs_map_name has value automountMapName
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_autofs_entry_object_class has value automount
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_autofs_entry_key has value automountKey
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sdap_get_map] (0x0200): Option ldap_autofs_entry_value has value automountInformation
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [be_process_init] (0x2000): autofs backend target successfully loaded from provider [ldap].
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [load_backend_module] (0x0200): no module name found in confdb, using [ldap].
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [be_process_init] (0x0020): No Session module provided for [TESTpippo.local] !!
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [load_backend_module] (0x0200): no module name found in confdb, using [ldap].
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [be_process_init] (0x0020): No host info module provided for [TESTpippo.local] !!
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [main] (0x0020): Backend provider (TESTpippo.local) started!
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): dbus conn: 7B1BF0
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): dbus conn: 7B1BF0
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7afa50/0x7b1070 (21), R/- (disabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7afa50/0x7afff0 (21), -/W (enabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7afa50/0x7b1070 (21), R/- (enabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7afa50/0x7afff0 (21), -/W (disabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_remove_timeout] (0x2000): 0x7b0980
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): dbus conn: 7B1BF0
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [id_callback] (0x0100): Got id ack and version (1) from Monitor
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_server_init_new_connection] (0x0200): Entering.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x7bb910.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_init_connection] (0x0200): Adding connection 7BB910
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_add_watch] (0x2000): 0x7bbca0/0x7afa90 (29), -/W (disabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7bbca0/0x7bb000 (29), R/- (enabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_server_init_new_connection] (0x0200): Got a connection
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x7b74e0]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): dbus conn: 7BB910
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7bbca0/0x7bb000 (29), R/- (disabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7bbca0/0x7afa90 (29), -/W (enabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7bbca0/0x7bb000 (29), R/- (enabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7bbca0/0x7afa90 (29), -/W (disabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_server_init_new_connection] (0x0200): Entering.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x7bd3f0.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_init_connection] (0x0200): Adding connection 7BD3F0
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_add_watch] (0x2000): 0x7c2070/0x7bc380 (30), -/W (disabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7c2070/0x7bd870 (30), R/- (enabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_server_init_new_connection] (0x0200): Got a connection
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x7c22e0]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): dbus conn: 7BD3F0
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7c2070/0x7bd870 (30), R/- (disabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7c2070/0x7bc380 (30), -/W (enabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7c2070/0x7bd870 (30), R/- (enabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_toggle_watch] (0x4000): 0x7c2070/0x7bc380 (30), -/W (disabled)
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): dbus conn: 7BB910
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_message_handler] (0x4000): Received SBUS method [RegisterService]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [client_registration] (0x0100): Cancel DP ID timeout [0x7b74e0]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [client_registration] (0x0100): Added Frontend client [NSS]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): dbus conn: 7BD3F0
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [sbus_message_handler] (0x4000): Received SBUS method [RegisterService]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [client_registration] (0x0100): Cancel DP ID timeout [0x7c22e0]
(Wed Jan  2 09:20:26 2013) [sssd[be[TESTpippo.local]]] [client_registration] (0x0100): Added Frontend client [PAM]
(Wed Jan  2 09:20:36 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): dbus conn: 7B1BF0
(Wed Jan  2 09:20:36 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan  2 09:20:36 2013) [sssd[be[TESTpippo.local]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_step] (0x4000): beginning to connect
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_server_status] (0x1000): Status of server 'miaomiao.testpippo.local' is 'name not resolved'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_port_status] (0x1000): Port status of port 636 for server 'miaomiao.testpippo.local' is 'neutral'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_server_status] (0x1000): Status of server 'miaomiao.testpippo.local' is 'name not resolved'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [resolv_is_address] (0x4000): [miaomiao.testpippo.local] does not look like an IP address
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [resolv_gethostbyname_step] (0x2000): Querying files
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'miaomiao.testpippo.local' in files
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [set_server_common_status] (0x0100): Marking server 'miaomiao.testpippo.local' as 'resolving name'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [set_server_common_status] (0x0100): Marking server 'miaomiao.testpippo.local' as 'name resolved'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [be_resolve_server_done] (0x1000): Saving the first resolved server
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [be_resolve_server_done] (0x0200): Found address for server miaomiao.testpippo.local: [2.2.2.2] TTL 7200
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldaps://miaomiao.testpippo.local'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sss_ldap_init_send] (0x4000): Using file descriptor [31] for LDAP connection.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldaps://miaomiao.testpippo.local:636/??base] with fd [31].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7c4490], connected[1], ops[0x7c49f0], ldap[0x7c50c0]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_parse_entry] (0x4000): OriginalDN: [].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7c4490], connected[1], ops[0x7c49f0], ldap[0x7c50c0]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_rootdse_done] (0x4000): Got rootdse
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_naming_context] (0x0200): Using value from [defaultNamingContext] as naming context.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [DC=testpippo,DC=local].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [common_parse_search_base] (0x0100): Search base added: [SUDO][DC=testpippo,DC=local][SUBTREE][]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 11431409 (int: 11431409)
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_send] (0x0100): Executing simple bind as: CN=baubau,OU=Service Accounts,DC=testpippo,DC=local
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_send] (0x2000): ldap simple bind sent, msgid = 2
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7c4490], connected[1], ops[0x8727f0], ldap[0x7c50c0]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7c4490], connected[1], ops[0x8727f0], ldap[0x7c50c0]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_BIND]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_done] (0x0200): Server returned no controls.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_done] (0x0080): Bind result: Success(0), no errmsg set
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [fo_set_port_status] (0x0100): Marking port 636 of server 'miaomiao.testpippo.local' as 'working'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [set_server_common_status] (0x0100): Marking server 'miaomiao.testpippo.local' as 'working'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_users_next_base] (0x0400): Searching for users with base [DC=testpippo,DC=local]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectclass=user)(sAMAccountName=*)(uidNumber=*)(gidNumber=*))][DC=testpippo,DC=local].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [displayName]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsUniqueId]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowLastChange]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMin]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMax]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowWarning]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowInactive]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowExpire]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowFlag]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbLastPwdChange]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPasswordExpiration]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [pwdAttribute]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [authorizedService]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsAccountLock]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [host]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginDisabled]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginExpirationTime]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginAllowedTimeMap]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 3
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 1 notifies
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7c4490], connected[1], ops[0x876d80], ldap[0x7c50c0]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7c4490], connected[1], ops[0x876d80], ldap[0x7c50c0]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_done] (0x0400): Search result: Operations error(1), 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_done] (0x0040): Unexpected result from ldap: Operations error(1), 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_done] (0x0100): sdap_get_generic_ext_recv failed [5]: Input/output error
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_done] (0x0200): communication error on cached connection, moving to next server
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_done] (0x4000): advising for connection retry #1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_done] (0x4000): releasing operation connection
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_handle_release] (0x2000): Trace: sh[0x7c4490], connected[1], ops[(nil)], ldap[0x7c50c0], destructor_lock[0], release_memory[0]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [remove_connection_callback] (0x4000): Successfully removed connection callback.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_step] (0x4000): beginning to connect
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_server_status] (0x1000): Status of server 'wofwof.testpippo.local' is 'name not resolved'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_port_status] (0x1000): Port status of port 636 for server 'wofwof.testpippo.local' is 'neutral'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_server_status] (0x1000): Status of server 'wofwof.testpippo.local' is 'name not resolved'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [resolv_is_address] (0x4000): [wofwof.testpippo.local] does not look like an IP address
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [resolv_gethostbyname_step] (0x2000): Querying files
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'wofwof.testpippo.local' in files
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [set_server_common_status] (0x0100): Marking server 'wofwof.testpippo.local' as 'resolving name'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [resolv_gethostbyname_step] (0x2000): Querying files
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'wofwof.testpippo.local' in files
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [resolv_gethostbyname_step] (0x2000): Querying DNS
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'wofwof.testpippo.local' in DNS
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 5 seconds
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [request_watch_destructor] (0x0400): Deleting request watch
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [set_server_common_status] (0x0100): Marking server 'wofwof.testpippo.local' as 'name resolved'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [be_resolve_server_done] (0x1000): Saving the first resolved server
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [be_resolve_server_done] (0x0200): Found address for server wofwof.testpippo.local: [1.1.1.1] TTL 3600
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldaps://wofwof.testpippo.local'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sss_ldap_init_send] (0x4000): Using file descriptor [33] for LDAP connection.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldaps://wofwof.testpippo.local:636/??base] with fd [33].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x8370b0], connected[1], ops[0x873140], ldap[0x86b900]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_parse_entry] (0x4000): OriginalDN: [].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x8370b0], connected[1], ops[0x873140], ldap[0x86b900]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_rootdse_done] (0x4000): Got rootdse
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 9627033 (int: 9627033)
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_send] (0x0100): Executing simple bind as: CN=baubau,OU=Service Accounts,DC=testpippo,DC=local
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_send] (0x2000): ldap simple bind sent, msgid = 2
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x8370b0], connected[1], ops[0x8719b0], ldap[0x86b900]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x8370b0], connected[1], ops[0x8719b0], ldap[0x86b900]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_BIND]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_done] (0x0200): Server returned no controls.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_done] (0x0080): Bind result: Success(0), no errmsg set
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [fo_set_port_status] (0x0100): Marking port 636 of server 'wofwof.testpippo.local' as 'working'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [set_server_common_status] (0x0100): Marking server 'wofwof.testpippo.local' as 'working'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_done] (0x2000): Old USN: 11431409, New USN: 9627033
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_users_next_base] (0x0400): Searching for users with base [DC=testpippo,DC=local]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectclass=user)(sAMAccountName=*)(uidNumber=*)(gidNumber=*))][DC=testpippo,DC=local].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [displayName]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsUniqueId]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowLastChange]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMin]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMax]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowWarning]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowInactive]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowExpire]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowFlag]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbLastPwdChange]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPasswordExpiration]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [pwdAttribute]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [authorizedService]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsAccountLock]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [host]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginDisabled]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginExpirationTime]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginAllowedTimeMap]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 3
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 1 notifies
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x8370b0], connected[1], ops[0x872660], ldap[0x86b900]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x8370b0], connected[1], ops[0x872660], ldap[0x86b900]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_done] (0x0400): Search result: Operations error(1), 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_done] (0x0040): Unexpected result from ldap: Operations error(1), 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_done] (0x0100): sdap_get_generic_ext_recv failed [5]: Input/output error
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_done] (0x0200): communication error on cached connection, moving to next server
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_done] (0x4000): advising for connection retry #2
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_done] (0x4000): releasing operation connection
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_handle_release] (0x2000): Trace: sh[0x8370b0], connected[1], ops[(nil)], ldap[0x86b900], destructor_lock[0], release_memory[0]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [remove_connection_callback] (0x4000): Successfully removed connection callback.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_step] (0x4000): beginning to connect
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_server_status] (0x1000): Status of server 'miaomiao.testpippo.local' is 'working'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_port_status] (0x1000): Port status of port 636 for server 'miaomiao.testpippo.local' is 'neutral'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_server_status] (0x1000): Status of server 'miaomiao.testpippo.local' is 'working'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [be_resolve_server_done] (0x1000): Saving the first resolved server
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [be_resolve_server_done] (0x0200): Found address for server miaomiao.testpippo.local: [2.2.2.2] TTL 7200
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldaps://miaomiao.testpippo.local'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sss_ldap_init_send] (0x4000): Using file descriptor [31] for LDAP connection.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldaps://miaomiao.testpippo.local:636/??base] with fd [31].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x8370b0], connected[1], ops[0x7c3fe0], ldap[0x851e30]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_parse_entry] (0x4000): OriginalDN: [].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x8370b0], connected[1], ops[0x7c3fe0], ldap[0x851e30]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_rootdse_done] (0x4000): Got rootdse
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 11431410 (int: 11431410)
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_send] (0x0100): Executing simple bind as: CN=baubau,OU=Service Accounts,DC=testpippo,DC=local
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_send] (0x2000): ldap simple bind sent, msgid = 2
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x8370b0], connected[1], ops[0x86bc90], ldap[0x851e30]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x8370b0], connected[1], ops[0x86bc90], ldap[0x851e30]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_BIND]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_done] (0x0200): Server returned no controls.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_done] (0x0080): Bind result: Success(0), no errmsg set
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [fo_set_port_status] (0x0100): Marking port 636 of server 'miaomiao.testpippo.local' as 'working'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [set_server_common_status] (0x0100): Marking server 'miaomiao.testpippo.local' as 'working'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_done] (0x2000): Old USN: 9627033, New USN: 11431410
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_users_next_base] (0x0400): Searching for users with base [DC=testpippo,DC=local]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectclass=user)(sAMAccountName=*)(uidNumber=*)(gidNumber=*))][DC=testpippo,DC=local].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [displayName]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsUniqueId]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowLastChange]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMin]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMax]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowWarning]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowInactive]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowExpire]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowFlag]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbLastPwdChange]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPasswordExpiration]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [pwdAttribute]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [authorizedService]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsAccountLock]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [host]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginDisabled]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginExpirationTime]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginAllowedTimeMap]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 3
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 1 notifies
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x8370b0], connected[1], ops[0x871ac0], ldap[0x851e30]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x8370b0], connected[1], ops[0x871ac0], ldap[0x851e30]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_done] (0x0400): Search result: Operations error(1), 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_done] (0x0040): Unexpected result from ldap: Operations error(1), 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_done] (0x0100): sdap_get_generic_ext_recv failed [5]: Input/output error
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_done] (0x0200): communication error on cached connection, moving to next server
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_done] (0x4000): advising for connection retry #3
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_done] (0x4000): releasing operation connection
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_handle_release] (0x2000): Trace: sh[0x8370b0], connected[1], ops[(nil)], ldap[0x851e30], destructor_lock[0], release_memory[0]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [remove_connection_callback] (0x4000): Successfully removed connection callback.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_step] (0x4000): beginning to connect
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_server_status] (0x1000): Status of server 'wofwof.testpippo.local' is 'working'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_port_status] (0x1000): Port status of port 636 for server 'wofwof.testpippo.local' is 'neutral'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [get_server_status] (0x1000): Status of server 'wofwof.testpippo.local' is 'working'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [be_resolve_server_done] (0x1000): Saving the first resolved server
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [be_resolve_server_done] (0x0200): Found address for server wofwof.testpippo.local: [1.1.1.1] TTL 3600
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldaps://wofwof.testpippo.local'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sss_ldap_init_send] (0x4000): Using file descriptor [31] for LDAP connection.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldaps://wofwof.testpippo.local:636/??base] with fd [31].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7c4bb0], connected[1], ops[0x85e670], ldap[0x86fd80]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_parse_entry] (0x4000): OriginalDN: [].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7c4bb0], connected[1], ops[0x85e670], ldap[0x86fd80]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_rootdse_done] (0x4000): Got rootdse
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 9627035 (int: 9627035)
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_send] (0x0100): Executing simple bind as: CN=baubau,OU=Service Accounts,DC=testpippo,DC=local
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_send] (0x2000): ldap simple bind sent, msgid = 2
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7c4bb0], connected[1], ops[0x8719d0], ldap[0x86fd80]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7c4bb0], connected[1], ops[0x8719d0], ldap[0x86fd80]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_BIND]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_done] (0x0200): Server returned no controls.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [simple_bind_done] (0x0080): Bind result: Success(0), no errmsg set
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [fo_set_port_status] (0x0100): Marking port 636 of server 'wofwof.testpippo.local' as 'working'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [set_server_common_status] (0x0100): Marking server 'wofwof.testpippo.local' as 'working'
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_done] (0x2000): Old USN: 11431410, New USN: 9627035
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_users_next_base] (0x0400): Searching for users with base [DC=testpippo,DC=local]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectclass=user)(sAMAccountName=*)(uidNumber=*)(gidNumber=*))][DC=testpippo,DC=local].
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [displayName]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsUniqueId]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowLastChange]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMin]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMax]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowWarning]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowInactive]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowExpire]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowFlag]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbLastPwdChange]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPasswordExpiration]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [pwdAttribute]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [authorizedService]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsAccountLock]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [host]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginDisabled]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginExpirationTime]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginAllowedTimeMap]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 3
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 1 notifies
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7c4bb0], connected[1], ops[0x871ab0], ldap[0x86fd80]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7c4bb0], connected[1], ops[0x871ab0], ldap[0x86fd80]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_done] (0x0400): Search result: Operations error(1), 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_ext_done] (0x0040): Unexpected result from ldap: Operations error(1), 000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this operation a successful bind must be completed on the connection., data 0, v1db1
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_get_generic_done] (0x0100): sdap_get_generic_ext_recv failed [5]: Input/output error
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_done] (0x0200): communication error on cached connection, moving to next server
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_done] (0x4000): too many communication failures, giving up...
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_op_done] (0x4000): releasing operation connection
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_id_release_conn_data] (0x4000): releasing unused connection
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [sdap_handle_release] (0x2000): Trace: sh[0x7c4bb0], connected[1], ops[(nil)], ldap[0x86fd80], destructor_lock[0], release_memory[0]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [remove_connection_callback] (0x4000): Successfully removed connection callback.
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [ldap_id_enum_users_done] (0x4000): User enumeration failed with: (5)[Input/output error]
(Wed Jan  2 09:20:37 2013) [sssd[be[TESTpippo.local]]] [ldap_id_enumerate_set_timer] (0x0400): Scheduling next enumeration at 1357115137.1804596
(Wed Jan  2 09:20:46 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): dbus conn: 7B1BF0
(Wed Jan  2 09:20:46 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan  2 09:20:46 2013) [sssd[be[TESTpippo.local]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): dbus conn: 7B1BF0
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [sbus_remove_watch] (0x2000): 0x7c2070/0x7bd870
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [sbus_remove_watch] (0x2000): 0x7c2070/0x7bc380
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x4000): dbus conn: 7BD3F0
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [sbus_dispatch] (0x0080): Connection is not open for dispatching.
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [be_client_destructor] (0x0400): Removed PAM client
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [sbus_remove_watch] (0x2000): 0x7bbca0/0x7bb000
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [sbus_remove_watch] (0x2000): 0x7bbca0/0x7afa90
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [sbus_remove_watch] (0x2000): 0x7b2710/0x7b28b0
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [remove_socket_symlink] (0x4000): The symlink points to [/var/lib/sss/pipes/private/sbus-dp_TESTpippo.local.11367]
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [remove_socket_symlink] (0x4000): The path including our pid is [/var/lib/sss/pipes/private/sbus-dp_TESTpippo.local.11367]
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [remove_socket_symlink] (0x4000): Removed the symlink
(Wed Jan  2 09:20:56 2013) [sssd[be[TESTpippo.local]]] [be_client_destructor] (0x0400): Removed NSS client