(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_initgr_common_store] (0x2000): Updating memberships for jharden
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): start ldb transaction (nesting: 1)
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): commit ldb transaction (nesting: 1)
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): commit ldb transaction (nesting: 0)
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_get_initgr_done] (0x4000): Initgroups done
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_destroy] (0x4000): releasing operation connection
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_id_op_done] (0x4000): releasing operation connection
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [acctinfo_initgroups_callback] (0x0080): NSS Service not conected
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: sh[0x16e7840], connected[1], ops[(nil)], ldap[0x16e60a0]
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000): dbus conn: 16DEE20
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_pam_handler] (0x0100): Got request with the following data
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): domain: default
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): user: jharden
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): service: sshd
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): tty: ssh
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): ruser:
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): rhost: test-server
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): authtok type: 1
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): authtok size: 13
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): newauthtok type: 0
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): newauthtok size: 0
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): priv: 1
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [pam_print_data] (0x0100): cli_pid: 24982
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP'
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [get_server_status] (0x1000): Status of server 'test-server' is 'working'
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [get_port_status] (0x1000): Port status of port 636 for server 'test-server' is 'working'
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [get_server_status] (0x1000): Status of server 'test-server' is 'working'
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_resolve_server_process] (0x0200): Found address for server test-server: [127.0.0.1] TTL 7200
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [auth_resolve_done] (0x2000): [ldaps://test-server/] is a secure channel. No need to run START_TLS
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sss_ldap_init_send] (0x4000): Using file descriptor [20] for LDAP connection.
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldaps://test-server:636/??base] with fd [20].
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [fo_set_port_status] (0x0100): Marking port 636 of server 'test-server' as 'working'
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [set_server_common_status] (0x0100): Marking server 'test-server' as 'working'
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x17c0950
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x17c0a70
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): Destroying timer event 0x17c0a70 "ltdb_timeout"
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): Ending timer event 0x17c0950 "ltdb_callback"
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [find_password_expiration_attributes] (0x4000): No password policy requested.
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [simple_bind_send] (0x0100): Executing simple bind as: uid=jharden,ou=Users,dc=example,dc=com
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [simple_bind_send] (0x2000): ldap simple bind sent, msgid = 1
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: sh[0x16e4410], connected[1], ops[0x1794440], ldap[0x1791f40]
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_BIND]
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [simple_bind_done] (0x1000): Server returned no controls.
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [simple_bind_done] (0x0400): Bind result: Invalid credentials(49), no errmsg set
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [sdap_handle_release] (0x2000): Trace: sh[0x16e4410], connected[1], ops[(nil)], ldap[0x1791f40], destructor_lock[0], release_memory[0]
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [remove_connection_callback] (0x4000): Successfully removed connection callback.
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 6, <NULL>) [Success]
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_pam_handler_callback] (0x0100): Sending result [6][default]
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [be_pam_handler_callback] (0x0100): Sent result [6][default]
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [ldb] (0x4000): start ldb transaction (nesting: 0)
(Thu Mar 20 23:25:04 2014) [sssd[be[default]]] [cleanup_users] (0x4000): Cache expiration is set to 0 days