Attachment 659395 Details for Bug 885105 – sssd_LDAP.log

sssd_LDAP.log

sssd_LDAP.log (text/plain), 78.71 KB, created by Nikolai Kondrashov on 2012-12-07 14:23:16 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Nikolai Kondrashov

Created: 2012-12-07 14:23:16 UTC

Size: 78.71 KB

patch

obsolete

>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [server_setup] (0x0400): CONFDB: /var/lib/sss/db/config.ldb
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [recreate_ares_channel] (0x0100): Initializing new c-ares channel
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [resolv_get_family_order] (0x1000): Lookup order: ipv4_first
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [fo_context_init] (0x0400): Created new fail over context, retry timeout is 30
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [confdb_get_domain_internal] (0x0400): No enumeration for [LDAP]!
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sysdb_domain_init_internal] (0x0200): DB File for LDAP: /var/lib/sss/db/cache_LDAP.ldb
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x922f20
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x9387c0
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0x9387c0 "ltdb_timeout"
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0x922f20 "ltdb_callback"
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x0400): asq: Unable to register control with rootdse!
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x922f20
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x9387f0
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0x9387f0 "ltdb_timeout"
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0x922f20 "ltdb_callback"
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x9388e0
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x938990
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0x938990 "ltdb_timeout"
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0x9388e0 "ltdb_callback"
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_init_connection] (0x0200): Adding connection 938EA0
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_add_watch] (0x2000): 0x939350/0x922a30 (16), -/W (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x939350/0x922a80 (16), R/- (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [monitor_common_send_id] (0x0100): Sending ID: (%BE_LDAP,1)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_add_timeout] (0x2000): 0x9396b0
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x939350/0x922a80 (16), R/- (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x939350/0x922a30 (16), -/W (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sss_names_init] (0x0100): Using re [(?P<name>[^@]+)@?(?P<domain>[^@]*$)].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [create_socket_symlink] (0x1000): Symlinking the dbus path /var/lib/sss/pipes/private/sbus-dp_LDAP.26392 to a link /var/lib/sss/pipes/private/sbus-dp_LDAP
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_new_server] (0x0400): D-BUS Server listening on unix:path=/var/lib/sss/pipes/private/sbus-dp_LDAP.26392,guid=05526756e4c0737b2102160200056c55
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_add_watch] (0x2000): 0x938d30/0x936b10 (17), R/- (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x1000): Loading backend [ldap] with path [/usr/lib64/sssd/libsss_ldap.so].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_uri has value ldaps://server.sss-test.test
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_backup_uri has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_search_base has value dc=example,dc=com
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_default_bind_dn has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_default_authtok_type has value password
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_default_authtok has no binary value.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_search_timeout has value 6
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_network_timeout has value 6
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_opt_timeout has value 6
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_tls_reqcert has value hard
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_user_search_base has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_user_search_scope has value sub
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_user_search_filter has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_group_search_base has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_group_search_scope has value sub
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_group_search_filter has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_service_search_base has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sudo_search_base has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sudo_full_refresh_interval has value 21600
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sudo_smart_refresh_interval has value 900
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sudo_use_host_filter is FALSE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sudo_hostnames has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sudo_ip has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sudo_include_netgroups is TRUE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sudo_include_regexp is TRUE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_autofs_search_base has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_schema has value rfc2307
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_offline_timeout has value 60
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_force_upper_case_realm is FALSE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_enumeration_refresh_timeout has value 300
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_purge_cache_timeout has value 10800
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_tls_cacert has value /etc/openldap/certs/cacert.asc
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_tls_cacertdir has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_tls_cert has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_tls_key has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_tls_cipher_suite has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_id_use_start_tls is FALSE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_id_mapping is FALSE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sasl_mech has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sasl_authid has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sasl_realm has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sasl_minssf has value -1
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_krb5_keytab has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_krb5_init_creds is TRUE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option krb5_server has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option krb5_backup_server has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option krb5_realm has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option krb5_canonicalize is TRUE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_pwd_policy has value none
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_referrals is TRUE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option account_cache_expiration has value 0
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_dns_service_name has value ldap
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_krb5_ticket_lifetime has value 86400
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_access_filter has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_netgroup_search_base has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_group_nesting_level has value 2
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_deref has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_account_expire_policy has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_access_order has value filter
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_chpass_uri has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_chpass_backup_uri has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_chpass_dns_service_name has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_chpass_update_last_change is FALSE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_enumeration_search_timeout has value 60
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_auth_disable_tls_never_use_in_production is FALSE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_page_size has value 1000
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_deref_threshold has value 10
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_sasl_canonicalize is FALSE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_connection_expire_timeout has value 900
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_disable_paging is FALSE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_idmap_range_min has value 200000
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_idmap_range_max has value 2000200000
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_idmap_range_size has value 200000
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_idmap_autorid_compat is FALSE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_idmap_default_domain has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_idmap_default_domain_sid has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_groups_use_matching_rule_in_chain is FALSE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [dp_get_options] (0x0400): Option ldap_initgroups_use_matching_rule_in_chain is FALSE
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldap_get_options] (0x0400): Option ldap_user_search_base set to dc=example,dc=com
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldap_get_options] (0x0400): Option ldap_group_search_base set to dc=example,dc=com
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldap_get_options] (0x0400): Option ldap_netgroup_search_base set to dc=example,dc=com
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldap_get_options] (0x0400): Option ldap_service_search_base set to dc=example,dc=com
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [common_parse_search_base] (0x0100): Search base added: [DEFAULT][dc=example,dc=com][SUBTREE][]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [common_parse_search_base] (0x0100): Search base added: [USER][dc=example,dc=com][SUBTREE][]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [common_parse_search_base] (0x0100): Search base added: [GROUP][dc=example,dc=com][SUBTREE][]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [common_parse_search_base] (0x0100): Search base added: [NETGROUP][dc=example,dc=com][SUBTREE][]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [common_parse_search_base] (0x0100): Search base added: [SERVICE][dc=example,dc=com][SUBTREE][]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_entry_usn has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_rootdse_last_usn has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_object_class has value posixAccount
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_name has value uid
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_pwd has value userPassword
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_uid_number has value uidNumber
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_gid_number has value gidNumber
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_gecos has value gecos
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_home_directory has value homeDirectory
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_shell has value loginShell
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_principal has value krbPrincipalName
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_fullname has value cn
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_member_of has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_uuid has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_objectsid has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_primary_group has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_modify_timestamp has value modifyTimestamp
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_entry_usn has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_last_change has value shadowLastChange
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_min has value shadowMin
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_max has value shadowMax
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_warning has value shadowWarning
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_inactive has value shadowInactive
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_expire has value shadowExpire
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_shadow_flag has value shadowFlag
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_krb_last_pwd_change has value krbLastPwdChange
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_krb_password_expiration has value krbPasswordExpiration
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_pwd_attribute has value pwdAttribute
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_authorized_service has value authorizedService
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_ad_account_expires has value accountExpires
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_ad_user_account_control has value userAccountControl
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_ns_account_lock has value nsAccountLock
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_authorized_host has value host
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_nds_login_disabled has value loginDisabled
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_nds_login_expiration_time has value loginExpirationTime
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_nds_login_allowed_time_map has value loginAllowedTimeMap
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_user_ssh_public_key has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_group_object_class has value posixGroup
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_group_name has value cn
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_group_pwd has value userPassword
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_group_gid_number has value gidNumber
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_group_member has value memberuid
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_group_uuid has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_group_objectsid has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_group_modify_timestamp has value modifyTimestamp
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_group_entry_usn has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_netgroup_object_class has value nisNetgroup
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_netgroup_name has value cn
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_netgroup_member has value memberNisNetgroup
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_netgroup_triple has value nisNetgroupTriple
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_netgroup_uuid has value nsUniqueId
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_netgroup_modify_timestamp has value modifyTimestamp
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_service_object_class has value ipService
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_service_name has value cn
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_service_port has value ipServicePort
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_service_proto has value ipServiceProtocol
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_service_entry_usn has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [krb5_try_kdcip] (0x0100): No KDC found in configuration, trying legacy option
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sssm_ldap_id_init] (0x1000): Service name for discovery set to ldap
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [fo_new_service] (0x0400): Creating new service 'LDAP'
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_urls_init] (0x0400): Added URI ldaps://server.sss-test.test
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [fo_add_server] (0x0080): Adding new server 'server.sss-test.test', to service 'LDAP'
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldap_id_cleanup_set_timer] (0x0400): Scheduling next cleanup at 1354889822.830452
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [be_process_init] (0x2000): ID backend target successfully loaded from provider [ldap].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sssm_ldap_id_init] (0x2000): Re-using sdap_id_ctx for this provider
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [be_process_init] (0x2000): AUTH backend target successfully loaded from provider [ldap].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x0200): no module name found in confdb, using [permit].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [be_process_init] (0x2000): ACCESS backend target successfully loaded from provider [permit].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x0200): no module name found in confdb, using [ldap].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sssm_ldap_id_init] (0x2000): Re-using sdap_id_ctx for this provider
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sssm_ldap_chpass_init] (0x4000): ldap_chpass_uri and ldap_chpass_dns_service_name not set, using ldap_uri.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [be_process_init] (0x2000): CHPASS backend target successfully loaded from provider [ldap].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sssm_ldap_id_init] (0x2000): Re-using sdap_id_ctx for this provider
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_sudo_init] (0x2000): Initializing sudo LDAP back end
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldap_get_sudo_options] (0x0200): Option ldap_sudo_search_base set to dc=example,dc=com
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [common_parse_search_base] (0x0100): Search base added: [SUDO][dc=example,dc=com][SUBTREE][]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_sudorule_object_class has value sudoRole
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_sudorule_name has value cn
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_sudorule_command has value sudoCommand
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_sudorule_host has value sudoHost
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_sudorule_user has value sudoUser
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_sudorule_option has value sudoOption
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_sudorule_runasuser has value sudoRunAsUser
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_sudorule_runasgroup has value sudoRunAsGroup
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_sudorule_notbefore has value sudoNotBefore
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_sudorule_notafter has value sudoNotAfter
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_sudorule_order has value sudoOrder
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_sudorule_entry_usn has no value 
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_sudo_get_ip_addresses] (0x2000): Found IP address: 192.168.124.4 in network 192.168.124.0/24
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_sudo_get_ip_addresses] (0x2000): Found IP address: fe80::5054:ff:fe9f:288b in network fe80::/64
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_sudo_get_hostnames_send] (0x2000): Found fqdn: client-rhel6.sss-test.test
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_sudo_get_hostnames_send] (0x2000): Found hostname: client-rhel6
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [be_process_init] (0x2000): SUDO backend target successfully loaded from provider [ldap].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x0200): no module name found in confdb, using [ldap].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sssm_ldap_id_init] (0x2000): Re-using sdap_id_ctx for this provider
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_autofs_init] (0x2000): Initializing autofs LDAP back end
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldap_get_autofs_options] (0x0200): Option ldap_autofs_search_base set to dc=example,dc=com
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [common_parse_search_base] (0x0100): Search base added: [AUTOFS][dc=example,dc=com][SUBTREE][]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_autofs_map_object_class has value automountMap
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_autofs_map_name has value ou
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_autofs_entry_object_class has value automount
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_autofs_entry_key has value cn
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_get_map] (0x0400): Option ldap_autofs_entry_value has value automountInformation
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [be_process_init] (0x2000): autofs backend target successfully loaded from provider [ldap].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x0200): no module name found in confdb, using [ldap].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [be_process_init] (0x0020): No selinux module provided for [LDAP] !!
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x0200): no module name found in confdb, using [ldap].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [be_process_init] (0x0020): No host info module provided for [LDAP] !!
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x0200): no module name found in confdb, using [ldap].
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [load_backend_module] (0x1000): Backend [ldap] already loaded.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [be_process_init] (0x0020): Subdomains are not supported for [LDAP] !!
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [main] (0x0400): Backend provider (LDAP) started!
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x944050
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x944170
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0x944170 "ltdb_timeout"
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0x944050 "ltdb_callback"
>
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_sudo_setup_periodical_refresh] (0x0400): Full refresh scheduled at: 1354889812
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 938EA0
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 938EA0
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_sudo_periodical_first_refresh_done] (0x0040): Periodical full refresh of sudo rules failed [12]: Cannot allocate memory)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_sudo_schedule_full_refresh] (0x0400): Full refresh scheduled at: 1354911412
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sdap_sudo_schedule_smart_refresh] (0x0400): Smart refresh scheduled at: 1354890712
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x939350/0x922a80 (16), R/- (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x939350/0x922a30 (16), -/W (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x939350/0x922a80 (16), R/- (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x939350/0x922a30 (16), -/W (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_remove_timeout] (0x2000): 0x9396b0
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 938EA0
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): Dispatching.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [id_callback] (0x0100): Got id ack and version (1) from Monitor
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_server_init_new_connection] (0x0200): Entering.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x9457b0.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_init_connection] (0x0200): Adding connection 9457B0
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_add_watch] (0x2000): 0x9448a0/0x939660 (19), -/W (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x9448a0/0x9431a0 (19), R/- (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_server_init_new_connection] (0x0200): Got a connection
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x9460d0]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 9457B0
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_server_init_new_connection] (0x0200): Entering.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x949f20.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_init_connection] (0x0200): Adding connection 949F20
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_add_watch] (0x2000): 0x94a4d0/0x946220 (20), -/W (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x94a4d0/0x946270 (20), R/- (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_server_init_new_connection] (0x0200): Got a connection
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x94a740]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 949F20
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_server_init_new_connection] (0x0200): Entering.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x94bc30.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_init_connection] (0x0200): Adding connection 94BC30
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_add_watch] (0x2000): 0x94c380/0x936350 (21), -/W (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x94c380/0x94a5c0 (21), R/- (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_server_init_new_connection] (0x0200): Got a connection
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x94c5f0]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 94BC30
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x94a4d0/0x946270 (20), R/- (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x94a4d0/0x946220 (20), -/W (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x94a4d0/0x946270 (20), R/- (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x94a4d0/0x946220 (20), -/W (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x9448a0/0x9431a0 (19), R/- (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x9448a0/0x939660 (19), -/W (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x9448a0/0x9431a0 (19), R/- (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x9448a0/0x939660 (19), -/W (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x94c380/0x94a5c0 (21), R/- (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x94c380/0x936350 (21), -/W (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x94c380/0x94a5c0 (21), R/- (enabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_toggle_watch] (0x4000): 0x94c380/0x936350 (21), -/W (disabled)
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 949F20
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): Dispatching.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_message_handler] (0x4000): Received SBUS method [RegisterService]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [client_registration] (0x0100): Cancel DP ID timeout [0x94a740]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [client_registration] (0x0100): Added Frontend client [PAM]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 9457B0
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): Dispatching.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_message_handler] (0x4000): Received SBUS method [RegisterService]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [client_registration] (0x0100): Cancel DP ID timeout [0x9460d0]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [client_registration] (0x0100): Added Frontend client [SUDO]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 94BC30
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): Dispatching.
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [sbus_message_handler] (0x4000): Received SBUS method [RegisterService]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [client_registration] (0x0100): Cancel DP ID timeout [0x94c5f0]
>(Fri Dec  7 16:16:52 2012) [sssd[be[LDAP]]] [client_registration] (0x0100): Added Frontend client [NSS]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 94BC30
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): Dispatching.
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_message_handler] (0x4000): Received SBUS method [getDomains]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [be_get_subdomains] (0x2000): Undefined backend target.
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 949F20
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): Dispatching.
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [be_get_account_info] (0x0100): Got request for [3][1][name=user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x950960
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x950ac0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0x950ac0 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0x950960 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x9508c0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x9523b0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0x9523b0 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0x9508c0 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_id_op_connect_step] (0x4000): beginning to connect
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP'
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [get_server_status] (0x1000): Status of server 'server.sss-test.test' is 'name not resolved'
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [get_port_status] (0x1000): Port status of port 636 for server 'server.sss-test.test' is 'neutral'
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [get_server_status] (0x1000): Status of server 'server.sss-test.test' is 'name not resolved'
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [resolv_is_address] (0x4000): [server.sss-test.test] does not look like an IP address
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [resolv_gethostbyname_step] (0x2000): Querying files
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'server.sss-test.test' in files
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [set_server_common_status] (0x0100): Marking server 'server.sss-test.test' as 'resolving name'
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [set_server_common_status] (0x0100): Marking server 'server.sss-test.test' as 'name resolved'
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [be_resolve_server_process] (0x0200): Found address for server server.sss-test.test: [192.168.124.2] TTL 7200
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldaps://server.sss-test.test'
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sss_ldap_init_send] (0x4000): Using file descriptor [22] for LDAP connection.
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldaps://server.sss-test.test:636/??base] with fd [22].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x9539d0], connected[1], ops[0x94fb90], ldap[0x954760]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_entry] (0x4000): OriginalDN: [].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultnamingcontext]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [vendorName]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [vendorVersion]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [dataversion]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [netscapemdsuffix]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x9539d0], connected[1], ops[0x94fb90], ldap[0x954760]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_rootdse_done] (0x2000): Got rootdse
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_server_opts_from_rootdse] (0x0200): No known USN scheme is supported by this server!
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_server_opts_from_rootdse] (0x0200): Will use modification timestamp as usn!
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1354890718
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_cli_auth_step] (0x1000): No authentication requested or SASL auth forced off
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [fo_set_port_status] (0x0100): Marking port 636 of server 'server.sss-test.test' as 'working'
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [set_server_common_status] (0x0100): Marking server 'server.sss-test.test' as 'working'
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [dc=example,dc=com]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(uid=user1)(objectclass=posixAccount))][dc=example,dc=com].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uid]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [homeDirectory]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPrincipalName]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowLastChange]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMin]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMax]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowWarning]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowInactive]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowExpire]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowFlag]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbLastPwdChange]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPasswordExpiration]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [pwdAttribute]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [authorizedService]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsAccountLock]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [host]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginDisabled]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginExpirationTime]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginAllowedTimeMap]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 2
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 1 notifies
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x9539d0], connected[1], ops[0xa332e0], ldap[0x954760]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x9539d0], connected[1], ops[0xa332e0], ldap[0x954760]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_entry] (0x4000): OriginalDN: [uid=user1,ou=People,dc=example,dc=com].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [uid]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [uidNumber]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [gidNumber]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [homeDirectory]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [loginShell]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [cn]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): No sub-attributes for [modifyTimestamp]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x9539d0], connected[1], ops[0xa332e0], ldap[0x954760]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 0)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_initgr_user] (0x4000): Storing the user
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_save_user] (0x4000): Save user
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_save_user] (0x2000): Adding originalDN [uid=user1,ou=People,dc=example,dc=com] to attributes of [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_save_user] (0x1000): Original memberOf is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20121207141259Z] to attributes of [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_save_user] (0x1000): Original USN value is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_save_user] (0x1000): User principal is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowLastChange is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMin is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMax is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowWarning is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowInactive is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowExpire is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowFlag is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): krbLastPwdChange is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): krbPasswordExpiration is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): pwdAttribute is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedService is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): adAccountExpires is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): adUserAccountControl is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): nsAccountLock is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedHost is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginDisabled is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginExpirationTime is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginAllowedTimeMap is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_attrs_add_ldap_attr] (0x2000): sshPublicKey is not available for [user1].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_save_user] (0x0400): Storing info for user user1
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 1)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa3d980
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa3daa0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa3daa0 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa3d980 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 2)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa40320
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa40440
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa40440 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa40320 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): commit ldb transaction (nesting: 2)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 2)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [userPassword] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa2ffb0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa40440
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa40440 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa2ffb0 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [userPrincipalName] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa45b20
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa2ff10
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa2ff10 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa45b20 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowLastChange] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa2ffb0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa40440
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa40440 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa2ffb0 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowMin] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa45b20
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa2ff10
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa2ff10 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa45b20 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowMax] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa2ffb0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa40440
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa40440 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa2ffb0 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowWarning] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa45b20
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa2ff10
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa2ff10 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa45b20 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowInactive] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa2ffb0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa40440
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa40440 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa2ffb0 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowExpire] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa45b20
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa2ff10
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa2ff10 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa45b20 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowFlag] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa2ffb0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa40440
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa40440 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa2ffb0 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [krbLastPwdChange] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa45b20
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa2ff10
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa2ff10 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa45b20 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [krbPasswordExpiration] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa2ffb0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa40440
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa40440 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa2ffb0 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [pwdAttribute] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa45b20
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa2ff10
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa2ff10 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa45b20 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [authorizedService] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa2ffb0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa40440
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa40440 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa2ffb0 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [adAccountExpires] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa45b20
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa2ff10
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa2ff10 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa45b20 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [adUserAccountControl] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa2ffb0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa40440
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa40440 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa2ffb0 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [nsAccountLock] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa45b20
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa2ff10
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa2ff10 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa45b20 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [authorizedHost] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa2ffb0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa40440
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa40440 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa2ffb0 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [ndsLoginDisabled] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa45b20
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa2ff10
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa2ff10 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa45b20 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [ndsLoginExpirationTime] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa2ffb0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa40440
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa40440 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa2ffb0 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sysdb_remove_attrs] (0x2000): Removing attribute [ndsLoginAllowedTimeMap] from [user1]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa45b20
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa2ff10
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa2ff10 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa45b20 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): commit ldb transaction (nesting: 2)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): commit ldb transaction (nesting: 1)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_initgr_user] (0x4000): Commit change
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): commit ldb transaction (nesting: 0)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa3dd20
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa3de40
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa3de40 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa3dd20 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_initgr_user] (0x4000): Process user's groups
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_initgr_rfc2307_next_base] (0x0400): Searching for groups with base [dc=example,dc=com]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(memberuid=user1)(objectclass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][dc=example,dc=com].
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 3
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x9539d0], connected[1], ops[0xa3ee50], ldap[0x954760]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x9539d0], connected[1], ops[0xa3ee50], ldap[0x954760]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_generic_ext_done] (0x1000): Total count [0]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xa30030
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xa3e7d0
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Destroying timer event 0xa3e7d0 "ltdb_timeout"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): Ending timer event 0xa30030 "ltdb_callback"
>
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 0)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_initgr_common_store] (0x2000): Updating memberships for user1
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): start ldb transaction (nesting: 1)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): commit ldb transaction (nesting: 1)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [ldb] (0x4000): commit ldb transaction (nesting: 0)
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_get_initgr_done] (0x4000): Initgroups done
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_id_op_destroy] (0x4000): releasing operation connection
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_id_op_done] (0x4000): releasing operation connection
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: sh[0x9539d0], connected[1], ops[(nil)], ldap[0x954760]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 949F20
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): Dispatching.
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [be_pam_handler] (0x0100): Got request with the following data
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): command: PAM_OPEN_SESSION
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): domain: LDAP
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): user: user1
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): service: su
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): tty: pts/0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): ruser: root
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): rhost: 
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): authtok type: 0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): authtok size: 0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): newauthtok type: 0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): newauthtok size: 0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): priv: 1
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): cli_pid: 26397
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [be_pam_handler] (0x0100): Sending result [0][LDAP]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 949F20
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): Dispatching.
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [be_pam_handler] (0x0100): Got request with the following data
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): domain: LDAP
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): user: user1
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): service: sudo
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): tty: /dev/pts/0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): ruser: user1
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): rhost: 
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): authtok type: 1
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): authtok size: 0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): newauthtok type: 0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): newauthtok size: 0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): priv: 0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): cli_pid: 26398
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 6, <NULL>) [Success]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [be_pam_handler_callback] (0x0100): Sending result [6][LDAP]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [be_pam_handler_callback] (0x0100): Sent result [6][LDAP]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 949F20
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): Dispatching.
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [be_pam_handler] (0x0100): Got request with the following data
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): command: PAM_CLOSE_SESSION
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): domain: LDAP
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): user: user1
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): service: su
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): tty: pts/0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): ruser: root
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): rhost: 
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): authtok type: 0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): authtok size: 0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): newauthtok type: 0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): newauthtok size: 0
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): priv: 1
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [pam_print_data] (0x0100): cli_pid: 26397
>(Fri Dec  7 16:16:58 2012) [sssd[be[LDAP]]] [be_pam_handler] (0x0100): Sending result [0][LDAP]
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [sbus_remove_watch] (0x2000): 0x9448a0/0x9431a0
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [sbus_remove_watch] (0x2000): 0x9448a0/0x939660
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): dbus conn: 9457B0
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [sbus_dispatch] (0x0080): Connection is not open for dispatching.
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [be_client_destructor] (0x0400): Removed SUDO client
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [sbus_remove_watch] (0x2000): 0x94a4d0/0x946270
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [sbus_remove_watch] (0x2000): 0x94a4d0/0x946220
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [sdap_handle_release] (0x2000): Trace: sh[0x9539d0], connected[1], ops[(nil)], ldap[0x954760], destructor_lock[0], release_memory[0]
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [remove_connection_callback] (0x4000): Successfully removed connection callback.
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [sbus_remove_watch] (0x2000): 0x938d30/0x936b10
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [remove_socket_symlink] (0x4000): The symlink points to [/var/lib/sss/pipes/private/sbus-dp_LDAP.26392]
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [remove_socket_symlink] (0x4000): The path including our pid is [/var/lib/sss/pipes/private/sbus-dp_LDAP.26392]
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [remove_socket_symlink] (0x4000): Removed the symlink
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [be_client_destructor] (0x0400): Removed NSS client
>(Fri Dec  7 16:17:01 2012) [sssd[be[LDAP]]] [be_client_destructor] (0x0400): Removed PAM client

Actions: View

Attachments on bug 885105: 659393 | 659394 | 659395 | 659396