[Freeipa-users] Only one AD user can able to login to IPA server

Tue Mar 17 11:38:41 UTC 2015

here is separated logs:

tail -f sssd_solaris.local.log

(Tue Mar 17 14:35:23 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:35:23 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:35:23 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [ping]
(Tue Mar 17 14:35:23 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:35:23 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]
(Tue Mar 17 14:35:33 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:35:33 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:35:33 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [ping]
(Tue Mar 17 14:35:33 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:35:33 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]
(Tue Mar 17 14:35:43 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:35:43 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:35:43 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [ping]
(Tue Mar 17 14:35:43 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:35:43 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [resetOffline]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [resetOffline]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[be_run_unconditional_online_cb] (0x0400): Running unconditional online
callbacks.
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [check_if_online]
(0x2000): Trying to go back online!
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [set_srv_data_status]
(0x0100): Marking SRV lookup of service 'gc_infra.com' as 'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server '(no name)' as 'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [set_srv_data_status]
(0x0100): Marking SRV lookup of service 'infra.com' as 'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server '(no name)' as 'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[set_server_common_status] (0x0100): Marking server
'kwtpocpbis01.solaris.local' as 'name not resolved'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server 'kwtpocpbis01.solaris.local' as 'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0400): Marking port 0 of duplicate server 'kwtpocpbis01.solaris.local'
as 'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name not
resolved'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [get_port_status]
(0x1000): Port status of port 0 for server 'kwtpocpbis01.solaris.local' is
'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name not
resolved'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [resolv_is_address]
(0x4000): [kwtpocpbis01.solaris.local] does not look like an IP address
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[resolv_gethostbyname_step] (0x2000): Querying files
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of
'kwtpocpbis01.solaris.local' in files
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[set_server_common_status] (0x0100): Marking server
'kwtpocpbis01.solaris.local' as 'resolving name'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[set_server_common_status] (0x0100): Marking server
'kwtpocpbis01.solaris.local' as 'name resolved'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x1000): Saving the first resolved server
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x0200): Found address for server
kwtpocpbis01.solaris.local: [172.16.107.244] TTL 7200
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [ipa_resolve_callback]
(0x0400): Constructed uri 'ldap://kwtpocpbis01.solaris.local'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sss_ldap_init_send]
(0x4000): Using file descriptor [22] for LDAP connection.
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sss_ldap_init_send]
(0x0400): Setting 6 seconds timeout for connecting
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to
[ldap://kwtpocpbis01.solaris.local:389/??base] with fd [22].
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_rootdse_send] (0x4000): Getting rootdse
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_print_server]
(0x2000): Searching 172.16.107.244
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(objectclass=*)][].
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[supportedLDAPVersion]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[supportedSASLMechanisms]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[domainControllerFunctionality]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[defaultNamingContext]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[highestCommittedUSN]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[0x7f6b7d2bae30],
ldap[0x7f6b7d265a00]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_entry]
(0x1000): OriginalDN: [].
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [objectClass]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [vendorName]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [vendorVersion]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [dataversion]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [netscapemdsuffix]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [changeLog]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [firstchangenumber]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [lastchangenumber]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [namingContexts]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedControl]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedExtension]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedLDAPVersion]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedSASLMechanisms]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [defaultNamingContext]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [lastUSN]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[0x7f6b7d2bae30],
ldap[0x7f6b7d265a00]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_rootdse_done] (0x2000): Got rootdse
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_server_opts_from_rootdse] (0x4000): USN value: 84359 (int: 84359)
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_kinit_send]
(0x0400): Attempting kinit (default, host/kwtpocpbis01.solaris.local,
SOLARIS.LOCAL, 86400)
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_kinit_next_kdc]
(0x1000): Resolving next KDC for service IPA
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name resolved'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name resolved'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x1000): Saving the first resolved server
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x0200): Found address for server
kwtpocpbis01.solaris.local: [172.16.107.244] TTL 7200
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT...
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[create_tgt_req_send_buffer] (0x0400): buffer size: 68
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [child_handler_setup]
(0x2000): Setting up signal handler up for pid [16437]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [child_handler_setup]
(0x2000): Signal handler set up for pid [16437]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[(nil)],
ldap[0x7f6b7d265a00]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [write_pipe_handler]
(0x0400): All data has been sent!
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [child_sig_handler]
(0x1000): Waiting for child [16437].
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [child_sig_handler]
(0x0100): child [16437] finished successfully.
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [read_pipe_handler]
(0x0400): EOF received, client finished
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_get_tgt_recv]
(0x0400): Child responded: 14 [Decrypt integrity check failed], expired on
[0]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_kinit_done]
(0x0100): Could not get TGT: 14 [Bad address]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_cli_kinit_done]
(0x0400): Cannot get a TGT: ret [1432158219](Authentication Failed)
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server 'kwtpocpbis01.solaris.local' as 'not
working'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0400): Marking port 0 of duplicate server 'kwtpocpbis01.solaris.local'
as 'not working'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_handle_release]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[(nil)],
ldap[0x7f6b7d265a00], destructor_lock[0], release_memory[0]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[remove_connection_callback] (0x4000): Successfully removed connection
callback.
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[check_online_callback] (0x0100): Backend returned: (3, 0, <NULL>)
[Internal Error (Success)]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [set_srv_data_status]
(0x0100): Marking SRV lookup of service 'gc_infra.com' as 'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server '(no name)' as 'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [set_srv_data_status]
(0x0100): Marking SRV lookup of service 'infra.com' as 'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server '(no name)' as 'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[set_server_common_status] (0x0100): Marking server
'kwtpocpbis01.solaris.local' as 'name not resolved'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server 'kwtpocpbis01.solaris.local' as 'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0400): Marking port 0 of duplicate server 'kwtpocpbis01.solaris.local'
as 'neutral'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [be_ptask_disable]
(0x0400): Task [Check if online (periodic)]: disabling task
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [be_run_online_cb]
(0x0080): Going online. Running callbacks.
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[ipa_subdom_reset_timeouts_cb] (0x4000): Resetting last_refreshed and
disabled_until.
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_sudo_schedule_refresh] (0x0400): Full refresh scheduled at: 1426592145
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_sudo_full_refresh_send] (0x0400): Issuing a full refresh of sudo rules
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_step] (0x4000): beginning to connect
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name not
resolved'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name not
resolved'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [resolv_is_address]
(0x4000): [kwtpocpbis01.solaris.local] does not look like an IP address
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[resolv_gethostbyname_step] (0x2000): Querying files
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of
'kwtpocpbis01.solaris.local' in files
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[set_server_common_status] (0x0100): Marking server
'kwtpocpbis01.solaris.local' as 'resolving name'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[set_server_common_status] (0x0100): Marking server
'kwtpocpbis01.solaris.local' as 'name resolved'
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x1000): Saving the first resolved server
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x0200): Found address for server
kwtpocpbis01.solaris.local: [172.16.107.244] TTL 7200
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sss_ldap_init_send]
(0x4000): Using file descriptor [22] for LDAP connection.
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sss_ldap_init_send]
(0x0400): Setting 6 seconds timeout for connecting
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to
[ldap://kwtpocpbis01.solaris.local:389/??base] with fd [22].
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_rootdse_send] (0x4000): Getting rootdse
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [sdap_print_server]
(0x2000): Searching 172.16.107.244
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(objectclass=*)][].
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[supportedLDAPVersion]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[supportedSASLMechanisms]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[domainControllerFunctionality]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[defaultNamingContext]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[highestCommittedUSN]
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]] [ad_online_cb]
(0x0400): The AD provider is online
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_step] (0x4000): waiting for connection to complete
(Tue Mar 17 14:35:45 2015) [sssd[be[solaris.local]]]
[delayed_online_authentication_callback] (0x0200): Backend is online,
starting delayed online authentication.
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[0x7f6b7d2bf090],
ldap[0x7f6b7d265a00]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_entry]
(0x1000): OriginalDN: [].
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [objectClass]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [vendorName]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [vendorVersion]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [dataversion]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [netscapemdsuffix]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [changeLog]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [firstchangenumber]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [lastchangenumber]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [namingContexts]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedControl]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedExtension]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedLDAPVersion]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedSASLMechanisms]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [defaultNamingContext]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [lastUSN]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[0x7f6b7d2bf090],
ldap[0x7f6b7d265a00]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_get_rootdse_done] (0x2000): Got rootdse
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_get_server_opts_from_rootdse] (0x4000): USN value: 84361 (int: 84361)
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_kinit_send]
(0x0400): Attempting kinit (default, host/kwtpocpbis01.solaris.local,
SOLARIS.LOCAL, 86400)
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_kinit_next_kdc]
(0x1000): Resolving next KDC for service IPA
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name resolved'
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name resolved'
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x1000): Saving the first resolved server
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x0200): Found address for server
kwtpocpbis01.solaris.local: [172.16.107.244] TTL 7200
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT...
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[create_tgt_req_send_buffer] (0x0400): buffer size: 68
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [child_handler_setup]
(0x2000): Setting up signal handler up for pid [16438]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [child_handler_setup]
(0x2000): Signal handler set up for pid [16438]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[(nil)],
ldap[0x7f6b7d265a00]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [write_pipe_handler]
(0x0400): All data has been sent!
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [child_sig_handler]
(0x1000): Waiting for child [16438].
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [child_sig_handler]
(0x0100): child [16438] finished successfully.
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [read_pipe_handler]
(0x0400): EOF received, client finished
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_get_tgt_recv]
(0x0400): Child responded: 14 [Decrypt integrity check failed], expired on
[0]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_kinit_done]
(0x0100): Could not get TGT: 14 [Bad address]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_cli_kinit_done]
(0x0400): Cannot get a TGT: ret [1432158219](Authentication Failed)
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server 'kwtpocpbis01.solaris.local' as 'not
working'
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0400): Marking port 0 of duplicate server 'kwtpocpbis01.solaris.local'
as 'not working'
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [sdap_handle_release]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[(nil)],
ldap[0x7f6b7d265a00], destructor_lock[0], release_memory[0]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[remove_connection_callback] (0x4000): Successfully removed connection
callback.
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_done] (0x4000): attempting failover retry on op #1
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_step] (0x4000): beginning to connect
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name resolved'
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [get_port_status]
(0x1000): Port status of port 0 for server 'kwtpocpbis01.solaris.local' is
'not working'
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_send] (0x0020): No available servers for service 'IPA'
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_done] (0x4000): attempting failover retry on op #2
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_step] (0x4000): waiting for connection to complete
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_id_release_conn_data] (0x4000): releasing unused connection
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[be_resolve_server_done] (0x1000): Server resolution failed: 5
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_done] (0x0020): Failed to connect, going offline (5
[Input/output error])
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [be_mark_offline]
(0x2000): Going offline!
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [be_mark_offline]
(0x2000): Enable check_if_online_ptask.
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [be_ptask_enable]
(0x0400): Task [Check if online (periodic)]: enabling task
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [be_ptask_schedule]
(0x0400): Task [Check if online (periodic)]: scheduling task 88 seconds
from now [1426592234]
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]] [be_run_offline_cb]
(0x0080): Going offline. Running callbacks.
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_done] (0x4000): notify offline to op #1
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_sudo_periodical_first_refresh_done] (0x0040): Periodical full refresh
of sudo rules failed [dp_error: 1] ([11]: Resource temporarily unavailable)
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_sudo_periodical_first_refresh_done] (0x0400): Data provider is
offline. Scheduling another full refresh in 16 minutes.
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_sudo_schedule_refresh] (0x0400): Full refresh scheduled at: 1426593106
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_done] (0x4000): notify offline to op #2
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[ipa_subdomains_get_conn_done] (0x0080): No IPA server is available, cannot
get the subdomain list while offline
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[sdap_id_release_conn_data] (0x4000): releasing unused connection
(Tue Mar 17 14:35:46 2015) [sssd[be[solaris.local]]]
[remove_krb5_info_files] (0x0200): Could not remove
[/var/lib/sss/pubconf/kpasswdinfo.SOLARIS.LOCAL], [2][No such file or
directory]
(Tue Mar 17 14:35:53 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:35:53 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:35:53 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [ping]
(Tue Mar 17 14:35:53 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:35:53 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]

(Tue Mar 17 14:36:03 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:36:03 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:36:03 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [ping]
(Tue Mar 17 14:36:03 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:36:03 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]
(Tue Mar 17 14:36:13 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:36:13 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:36:13 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [ping]
(Tue Mar 17 14:36:13 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:36:13 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [resetOffline]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [resetOffline]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[be_run_unconditional_online_cb] (0x0400): Running unconditional online
callbacks.
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [check_if_online]
(0x2000): Trying to go back online!
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [set_srv_data_status]
(0x0100): Marking SRV lookup of service 'gc_infra.com' as 'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server '(no name)' as 'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [set_srv_data_status]
(0x0100): Marking SRV lookup of service 'infra.com' as 'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server '(no name)' as 'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[set_server_common_status] (0x0100): Marking server
'kwtpocpbis01.solaris.local' as 'name not resolved'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server 'kwtpocpbis01.solaris.local' as 'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0400): Marking port 0 of duplicate server 'kwtpocpbis01.solaris.local'
as 'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name not
resolved'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [get_port_status]
(0x1000): Port status of port 0 for server 'kwtpocpbis01.solaris.local' is
'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name not
resolved'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [resolv_is_address]
(0x4000): [kwtpocpbis01.solaris.local] does not look like an IP address
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[resolv_gethostbyname_step] (0x2000): Querying files
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of
'kwtpocpbis01.solaris.local' in files
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[set_server_common_status] (0x0100): Marking server
'kwtpocpbis01.solaris.local' as 'resolving name'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[set_server_common_status] (0x0100): Marking server
'kwtpocpbis01.solaris.local' as 'name resolved'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x1000): Saving the first resolved server
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x0200): Found address for server
kwtpocpbis01.solaris.local: [172.16.107.244] TTL 7200
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [ipa_resolve_callback]
(0x0400): Constructed uri 'ldap://kwtpocpbis01.solaris.local'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sss_ldap_init_send]
(0x4000): Using file descriptor [22] for LDAP connection.
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sss_ldap_init_send]
(0x0400): Setting 6 seconds timeout for connecting
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to
[ldap://kwtpocpbis01.solaris.local:389/??base] with fd [22].
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_rootdse_send] (0x4000): Getting rootdse
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_print_server]
(0x2000): Searching 172.16.107.244
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(objectclass=*)][].
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[supportedLDAPVersion]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[supportedSASLMechanisms]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[domainControllerFunctionality]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[defaultNamingContext]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[highestCommittedUSN]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[0x7f6b7d2bae30],
ldap[0x7f6b7d265a00]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_entry]
(0x1000): OriginalDN: [].
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [objectClass]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [vendorName]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [vendorVersion]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [dataversion]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [netscapemdsuffix]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [changeLog]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [firstchangenumber]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [lastchangenumber]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [namingContexts]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedControl]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedExtension]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedLDAPVersion]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedSASLMechanisms]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [defaultNamingContext]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [lastUSN]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[0x7f6b7d2bae30],
ldap[0x7f6b7d265a00]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_rootdse_done] (0x2000): Got rootdse
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_server_opts_from_rootdse] (0x4000): USN value: 84363 (int: 84363)
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_kinit_send]
(0x0400): Attempting kinit (default, host/kwtpocpbis01.solaris.local,
SOLARIS.LOCAL, 86400)
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_kinit_next_kdc]
(0x1000): Resolving next KDC for service IPA
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name resolved'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name resolved'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x1000): Saving the first resolved server
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x0200): Found address for server
kwtpocpbis01.solaris.local: [172.16.107.244] TTL 7200
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT...
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[create_tgt_req_send_buffer] (0x0400): buffer size: 68
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [child_handler_setup]
(0x2000): Setting up signal handler up for pid [16441]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [child_handler_setup]
(0x2000): Signal handler set up for pid [16441]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[(nil)],
ldap[0x7f6b7d265a00]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [write_pipe_handler]
(0x0400): All data has been sent!
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [child_sig_handler]
(0x1000): Waiting for child [16441].
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [child_sig_handler]
(0x0100): child [16441] finished successfully.
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [read_pipe_handler]
(0x0400): EOF received, client finished
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_get_tgt_recv]
(0x0400): Child responded: 14 [Decrypt integrity check failed], expired on
[0]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_kinit_done]
(0x0100): Could not get TGT: 14 [Bad address]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_cli_kinit_done]
(0x0400): Cannot get a TGT: ret [1432158219](Authentication Failed)
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server 'kwtpocpbis01.solaris.local' as 'not
working'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0400): Marking port 0 of duplicate server 'kwtpocpbis01.solaris.local'
as 'not working'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_handle_release]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[(nil)],
ldap[0x7f6b7d265a00], destructor_lock[0], release_memory[0]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[remove_connection_callback] (0x4000): Successfully removed connection
callback.
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[check_online_callback] (0x0100): Backend returned: (3, 0, <NULL>)
[Internal Error (Success)]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [set_srv_data_status]
(0x0100): Marking SRV lookup of service 'gc_infra.com' as 'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server '(no name)' as 'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [set_srv_data_status]
(0x0100): Marking SRV lookup of service 'infra.com' as 'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server '(no name)' as 'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[set_server_common_status] (0x0100): Marking server
'kwtpocpbis01.solaris.local' as 'name not resolved'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server 'kwtpocpbis01.solaris.local' as 'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0400): Marking port 0 of duplicate server 'kwtpocpbis01.solaris.local'
as 'neutral'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [be_ptask_disable]
(0x0400): Task [Check if online (periodic)]: disabling task
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [be_run_online_cb]
(0x0080): Going online. Running callbacks.
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[ipa_subdom_reset_timeouts_cb] (0x4000): Resetting last_refreshed and
disabled_until.
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_sudo_schedule_refresh] (0x0400): Full refresh scheduled at: 1426592175
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_sudo_full_refresh_send] (0x0400): Issuing a full refresh of sudo rules
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_step] (0x4000): beginning to connect
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name not
resolved'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name not
resolved'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [resolv_is_address]
(0x4000): [kwtpocpbis01.solaris.local] does not look like an IP address
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[resolv_gethostbyname_step] (0x2000): Querying files
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of
'kwtpocpbis01.solaris.local' in files
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[set_server_common_status] (0x0100): Marking server
'kwtpocpbis01.solaris.local' as 'resolving name'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[set_server_common_status] (0x0100): Marking server
'kwtpocpbis01.solaris.local' as 'name resolved'
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x1000): Saving the first resolved server
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x0200): Found address for server
kwtpocpbis01.solaris.local: [172.16.107.244] TTL 7200
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sss_ldap_init_send]
(0x4000): Using file descriptor [22] for LDAP connection.
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sss_ldap_init_send]
(0x0400): Setting 6 seconds timeout for connecting
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to
[ldap://kwtpocpbis01.solaris.local:389/??base] with fd [22].
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_rootdse_send] (0x4000): Getting rootdse
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [sdap_print_server]
(0x2000): Searching 172.16.107.244
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
[(objectclass=*)][].
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[supportedLDAPVersion]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[supportedSASLMechanisms]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[domainControllerFunctionality]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[defaultNamingContext]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x1000): Requesting attrs:
[highestCommittedUSN]
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]] [ad_online_cb]
(0x0400): The AD provider is online
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_step] (0x4000): waiting for connection to complete
(Tue Mar 17 14:36:15 2015) [sssd[be[solaris.local]]]
[delayed_online_authentication_callback] (0x0200): Backend is online,
starting delayed online authentication.
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[0x7f6b7d2bae30],
ldap[0x7f6b7d265a00]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_entry]
(0x1000): OriginalDN: [].
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [objectClass]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [vendorName]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [vendorVersion]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [dataversion]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [netscapemdsuffix]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [changeLog]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [firstchangenumber]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [lastchangenumber]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [namingContexts]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedControl]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedExtension]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedLDAPVersion]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [supportedSASLMechanisms]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [defaultNamingContext]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
(0x2000): No sub-attributes for [lastUSN]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[0x7f6b7d2bae30],
ldap[0x7f6b7d265a00]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_process_message]
(0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_get_rootdse_done] (0x2000): Got rootdse
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_get_server_opts_from_rootdse] (0x4000): USN value: 84365 (int: 84365)
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_kinit_send]
(0x0400): Attempting kinit (default, host/kwtpocpbis01.solaris.local,
SOLARIS.LOCAL, 86400)
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_kinit_next_kdc]
(0x1000): Resolving next KDC for service IPA
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name resolved'
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name resolved'
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x1000): Saving the first resolved server
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[be_resolve_server_process] (0x0200): Found address for server
kwtpocpbis01.solaris.local: [172.16.107.244] TTL 7200
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT...
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[create_tgt_req_send_buffer] (0x0400): buffer size: 68
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [child_handler_setup]
(0x2000): Setting up signal handler up for pid [16442]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [child_handler_setup]
(0x2000): Signal handler set up for pid [16442]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[(nil)],
ldap[0x7f6b7d265a00]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [write_pipe_handler]
(0x0400): All data has been sent!
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [child_sig_handler]
(0x1000): Waiting for child [16442].
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [child_sig_handler]
(0x0100): child [16442] finished successfully.
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [read_pipe_handler]
(0x0400): EOF received, client finished
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_get_tgt_recv]
(0x0400): Child responded: 14 [Decrypt integrity check failed], expired on
[0]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_kinit_done]
(0x0100): Could not get TGT: 14 [Bad address]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_cli_kinit_done]
(0x0400): Cannot get a TGT: ret [1432158219](Authentication Failed)
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0100): Marking port 0 of server 'kwtpocpbis01.solaris.local' as 'not
working'
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
(0x0400): Marking port 0 of duplicate server 'kwtpocpbis01.solaris.local'
as 'not working'
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [sdap_handle_release]
(0x2000): Trace: sh[0x7f6b7d2c3140], connected[1], ops[(nil)],
ldap[0x7f6b7d265a00], destructor_lock[0], release_memory[0]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[remove_connection_callback] (0x4000): Successfully removed connection
callback.
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_done] (0x4000): attempting failover retry on op #1
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_step] (0x4000): beginning to connect
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [get_server_status]
(0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name resolved'
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [get_port_status]
(0x1000): Port status of port 0 for server 'kwtpocpbis01.solaris.local' is
'not working'
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[fo_resolve_service_send] (0x0020): No available servers for service 'IPA'
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_done] (0x4000): attempting failover retry on op #2
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_step] (0x4000): waiting for connection to complete
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_id_release_conn_data] (0x4000): releasing unused connection
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[be_resolve_server_done] (0x1000): Server resolution failed: 5
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_done] (0x0020): Failed to connect, going offline (5
[Input/output error])
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [be_mark_offline]
(0x2000): Going offline!
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [be_mark_offline]
(0x2000): Enable check_if_online_ptask.
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [be_ptask_enable]
(0x0400): Task [Check if online (periodic)]: enabling task
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [be_ptask_schedule]
(0x0400): Task [Check if online (periodic)]: scheduling task 78 seconds
from now [1426592254]
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]] [be_run_offline_cb]
(0x0080): Going offline. Running callbacks.
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_done] (0x4000): notify offline to op #1
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_sudo_periodical_first_refresh_done] (0x0040): Periodical full refresh
of sudo rules failed [dp_error: 1] ([11]: Resource temporarily unavailable)
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_sudo_periodical_first_refresh_done] (0x0400): Data provider is
offline. Scheduling another full refresh in 16 minutes.
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_sudo_schedule_refresh] (0x0400): Full refresh scheduled at: 1426593136
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_id_op_connect_done] (0x4000): notify offline to op #2
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[ipa_subdomains_get_conn_done] (0x0080): No IPA server is available, cannot
get the subdomain list while offline
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[sdap_id_release_conn_data] (0x4000): releasing unused connection
(Tue Mar 17 14:36:16 2015) [sssd[be[solaris.local]]]
[remove_krb5_info_files] (0x0200): Could not remove
[/var/lib/sss/pubconf/kpasswdinfo.SOLARIS.LOCAL], [2][No such file or
directory]
(Tue Mar 17 14:36:18 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d2a5140
(Tue Mar 17 14:36:18 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:36:18 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [getAccountInfo]
(Tue Mar 17 14:36:18 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:36:18 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [getAccountInfo]
(Tue Mar 17 14:36:18 2015) [sssd[be[solaris.local]]] [be_get_account_info]
(0x0200): Got request for [0x1001][1][name=bobby]
(Tue Mar 17 14:36:18 2015) [sssd[be[solaris.local]]] [be_get_account_info]
(0x0100): Request processed. Returned 1,11,Fast reply - offline
(Tue Mar 17 14:36:18 2015) [sssd[be[solaris.local]]] [be_req_set_domain]
(0x0400): Changing request domain from [solaris.local] to [infra.com]
(Tue Mar 17 14:36:23 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:36:23 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:36:23 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [ping]
(Tue Mar 17 14:36:23 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:36:23 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]
(Tue Mar 17 14:36:33 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:36:33 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:36:33 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [ping]
(Tue Mar 17 14:36:33 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:36:33 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d2a5140
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [getAccountInfo]
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [getAccountInfo]
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [be_get_account_info]
(0x0200): Got request for [0x1001][1][name=bobby]
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [be_get_account_info]
(0x0100): Request processed. Returned 1,11,Fast reply - offline
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [be_req_set_domain]
(0x0400): Changing request domain from [solaris.local] to [infra.com]
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d2a5140
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [getAccountInfo]
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [getAccountInfo]
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [be_get_account_info]
(0x0200): Got request for [0x1001][1][name=bobby]
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [be_get_account_info]
(0x0100): Request processed. Returned 1,11,Fast reply - offline
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [be_req_set_domain]
(0x0400): Changing request domain from [solaris.local] to [infra.com]
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d2a5140
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [getAccountInfo]
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [getAccountInfo]
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [be_get_account_info]
(0x0200): Got request for [0x1001][1][name=bobby]
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [be_get_account_info]
(0x0100): Request processed. Returned 1,11,Fast reply - offline
(Tue Mar 17 14:36:35 2015) [sssd[be[solaris.local]]] [be_req_set_domain]
(0x0400): Changing request domain from [solaris.local] to [infra.com]
(Tue Mar 17 14:36:43 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:36:43 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:36:43 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [ping]
(Tue Mar 17 14:36:43 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:36:43 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]
(Tue Mar 17 14:36:53 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:36:53 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:36:53 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [ping]
(Tue Mar 17 14:36:53 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:36:53 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]
(Tue Mar 17 14:37:03 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): dbus conn: 0x7f6b7d266a70
(Tue Mar 17 14:37:03 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
(0x4000): Dispatching.
(Tue Mar 17 14:37:03 2015) [sssd[be[solaris.local]]] [sbus_message_handler]
(0x4000): Received SBUS method [ping]
(Tue Mar 17 14:37:03 2015) [sssd[be[solaris.local]]]
[sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
(Tue Mar 17 14:37:03 2015) [sssd[be[solaris.local]]]
[sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping]

On Tue, Mar 17, 2015 at 2:34 PM, Ben .T.George <bentech4you at gmail.com>
wrote:

> Oops sorry
> here is the logs
>
> ==> sssd_pam.log <==
> (Tue Mar 17 14:33:23 2015) [sssd[pam]] [sbus_dispatch] (0x4000): dbus
> conn: 0x7fdea7263bd0
> (Tue Mar 17 14:33:23 2015) [sssd[pam]] [sbus_dispatch] (0x4000):
> Dispatching.
> (Tue Mar 17 14:33:23 2015) [sssd[pam]] [sbus_message_handler] (0x4000):
> Received SBUS method [ping]
> (Tue Mar 17 14:33:23 2015) [sssd[pam]] [sbus_get_sender_id_send] (0x2000):
> Not a sysbus message, quit
> (Tue Mar 17 14:33:23 2015) [sssd[pam]] [sbus_handler_got_caller_id]
> (0x4000): Received SBUS method [ping]
>
> ==> sssd.log <==
> (Tue Mar 17 14:33:23 2015) [sssd] [ping_check] (0x0100): Service
> solaris.local replied to ping
> (Tue Mar 17 14:33:23 2015) [sssd] [ping_check] (0x0100): Service pac
> replied to ping
> (Tue Mar 17 14:33:23 2015) [sssd] [ping_check] (0x0100): Service sudo
> replied to ping
> (Tue Mar 17 14:33:23 2015) [sssd] [ping_check] (0x0100): Service ssh
> replied to ping
> (Tue Mar 17 14:33:23 2015) [sssd] [ping_check] (0x0100): Service pam
> replied to ping
> (Tue Mar 17 14:33:23 2015) [sssd] [ping_check] (0x0100): Service nss
> replied to ping
>
> ==> sssd_nss.log <==
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0400):
> Running command [17] with input [bobby at infra.com].
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_parse_name_for_domains]
> (0x0200): name 'bobby at infra.com' matched expression for domain 'infra.com',
> user is bobby
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0100):
> Requesting info for [bobby] from [infra.com]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100):
> Requesting info for [bobby at infra.com]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_dp_issue_request] (0x0400):
> Issuing request for [0x7f426adbfb50:1:bobby at infra.com]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_dp_get_account_msg] (0x0400):
> Creating request for [infra.com][4097][1][name=bobby]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_dp_internal_get_send]
> (0x0400): Entering request [0x7f426adbfb50:1:bobby at infra.com]
>
> ==> sssd_solaris.local.log <==
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
> (0x4000): dbus conn: 0x7f6b7d2a5140
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
> (0x4000): Dispatching.
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]]
> [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo]
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]]
> [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]]
> [sbus_handler_got_caller_id] (0x4000): Received SBUS method [getAccountInfo]
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [be_get_account_info]
> (0x0200): Got request for [0x1001][1][name=bobby]
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [be_get_account_info]
> (0x0100): Request processed. Returned 1,11,Fast reply - offline
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [be_req_set_domain]
> (0x0400): Changing request domain from [solaris.local] to [infra.com]
>
> ==> sssd_nss.log <==
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [nss_cmd_getby_dp_callback]
> (0x0040): Unable to get information from Data Provider
> Error: 1, 11, Fast reply - offline
> Will try to return what we have in cache
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_dp_req_destructor] (0x0400):
> Deleting request: [0x7f426adbfb50:1:bobby at infra.com]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0400):
> Running command [17] with input [bobby at infra.com].
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_parse_name_for_domains]
> (0x0200): name 'bobby at infra.com' matched expression for domain 'infra.com',
> user is bobby
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0100):
> Requesting info for [bobby] from [infra.com]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100):
> Requesting info for [bobby at infra.com]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_dp_issue_request] (0x0400):
> Issuing request for [0x7f426adbfb50:1:bobby at infra.com]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_dp_get_account_msg] (0x0400):
> Creating request for [infra.com][4097][1][name=bobby]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_dp_internal_get_send]
> (0x0400): Entering request [0x7f426adbfb50:1:bobby at infra.com]
>
> ==> sssd_solaris.local.log <==
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
> (0x4000): dbus conn: 0x7f6b7d2a5140
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
> (0x4000): Dispatching.
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]]
> [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo]
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]]
> [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]]
> [sbus_handler_got_caller_id] (0x4000): Received SBUS method [getAccountInfo]
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [be_get_account_info]
> (0x0200): Got request for [0x1001][1][name=bobby]
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [be_get_account_info]
> (0x0100): Request processed. Returned 1,11,Fast reply - offline
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [be_req_set_domain]
> (0x0400): Changing request domain from [solaris.local] to [infra.com]
>
> ==> sssd_nss.log <==
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [nss_cmd_getby_dp_callback]
> (0x0040): Unable to get information from Data Provider
> Error: 1, 11, Fast reply - offline
> Will try to return what we have in cache
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_dp_req_destructor] (0x0400):
> Deleting request: [0x7f426adbfb50:1:bobby at infra.com]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0400):
> Running command [17] with input [bobby at infra.com].
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_parse_name_for_domains]
> (0x0200): name 'bobby at infra.com' matched expression for domain 'infra.com',
> user is bobby
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [nss_cmd_getbynam] (0x0100):
> Requesting info for [bobby] from [infra.com]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100):
> Requesting info for [bobby at infra.com]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_dp_issue_request] (0x0400):
> Issuing request for [0x7f426adbfb50:1:bobby at infra.com]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_dp_get_account_msg] (0x0400):
> Creating request for [infra.com][4097][1][name=bobby]
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_dp_internal_get_send]
> (0x0400): Entering request [0x7f426adbfb50:1:bobby at infra.com]
>
> ==> sssd_solaris.local.log <==
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
> (0x4000): dbus conn: 0x7f6b7d2a5140
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
> (0x4000): Dispatching.
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]]
> [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo]
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]]
> [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]]
> [sbus_handler_got_caller_id] (0x4000): Received SBUS method [getAccountInfo]
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [be_get_account_info]
> (0x0200): Got request for [0x1001][1][name=bobby]
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [be_get_account_info]
> (0x0100): Request processed. Returned 1,11,Fast reply - offline
> (Tue Mar 17 14:33:27 2015) [sssd[be[solaris.local]]] [be_req_set_domain]
> (0x0400): Changing request domain from [solaris.local] to [infra.com]
>
> ==> sssd_nss.log <==
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [nss_cmd_getby_dp_callback]
> (0x0040): Unable to get information from Data Provider
> Error: 1, 11, Fast reply - offline
> Will try to return what we have in cache
> (Tue Mar 17 14:33:27 2015) [sssd[nss]] [sss_dp_req_destructor] (0x0400):
> Deleting request: [0x7f426adbfb50:1:bobby at infra.com]
>
> ==> sssd.log <==
> (Tue Mar 17 14:33:30 2015) [sssd] [message_type] (0x0200): netlink Message
> type: 25
>
> ==> sssd_solaris.local.log <==
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
> (0x4000): dbus conn: 0x7f6b7d266a70
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sbus_dispatch]
> (0x4000): Dispatching.
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sbus_message_handler] (0x4000): Received SBUS method [resetOffline]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sbus_handler_got_caller_id] (0x4000): Received SBUS method [resetOffline]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [be_run_unconditional_online_cb] (0x0400): Running unconditional online
> callbacks.
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [check_if_online]
> (0x2000): Trying to go back online!
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [set_srv_data_status]
> (0x0100): Marking SRV lookup of service 'gc_infra.com' as 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
> (0x0100): Marking port 0 of server '(no name)' as 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [set_srv_data_status]
> (0x0100): Marking SRV lookup of service 'infra.com' as 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
> (0x0100): Marking port 0 of server '(no name)' as 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [set_server_common_status] (0x0100): Marking server
> 'kwtpocpbis01.solaris.local' as 'name not resolved'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
> (0x0100): Marking port 0 of server 'kwtpocpbis01.solaris.local' as 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
> (0x0400): Marking port 0 of duplicate server 'kwtpocpbis01.solaris.local'
> as 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [get_server_status]
> (0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name not
> resolved'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [get_port_status]
> (0x1000): Port status of port 0 for server 'kwtpocpbis01.solaris.local' is
> 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
> seconds
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [get_server_status]
> (0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name not
> resolved'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [resolv_is_address]
> (0x4000): [kwtpocpbis01.solaris.local] does not look like an IP address
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [resolv_gethostbyname_step] (0x2000): Querying files
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of
> 'kwtpocpbis01.solaris.local' in files
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [set_server_common_status] (0x0100): Marking server
> 'kwtpocpbis01.solaris.local' as 'resolving name'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [set_server_common_status] (0x0100): Marking server
> 'kwtpocpbis01.solaris.local' as 'name resolved'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [be_resolve_server_process] (0x1000): Saving the first resolved server
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [be_resolve_server_process] (0x0200): Found address for server
> kwtpocpbis01.solaris.local: [172.16.107.244] TTL 7200
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [ipa_resolve_callback] (0x0400): Constructed uri
> 'ldap://kwtpocpbis01.solaris.local'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sss_ldap_init_send]
> (0x4000): Using file descriptor [22] for LDAP connection.
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sss_ldap_init_send]
> (0x0400): Setting 6 seconds timeout for connecting
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to
> [ldap://kwtpocpbis01.solaris.local:389/??base] with fd [22].
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_rootdse_send] (0x4000): Getting rootdse
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_print_server]
> (0x2000): Searching 172.16.107.244
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
> [(objectclass=*)][].
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs:
> [supportedLDAPVersion]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs:
> [supportedSASLMechanisms]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs:
> [domainControllerFunctionality]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs:
> [defaultNamingContext]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs:
> [highestCommittedUSN]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_process_result]
> (0x2000): Trace: sh[0x7f6b7d2c6140], connected[1], ops[0x7f6b7d2bf090],
> ldap[0x7f6b7d265a00]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_entry]
> (0x1000): OriginalDN: [].
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [objectClass]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [vendorName]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [vendorVersion]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [dataversion]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [netscapemdsuffix]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [changeLog]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [firstchangenumber]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [lastchangenumber]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [namingContexts]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [supportedControl]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [supportedExtension]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [supportedLDAPVersion]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [supportedSASLMechanisms]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [defaultNamingContext]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_parse_range]
> (0x2000): No sub-attributes for [lastUSN]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_process_result]
> (0x2000): Trace: sh[0x7f6b7d2c6140], connected[1], ops[0x7f6b7d2bf090],
> ldap[0x7f6b7d265a00]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
> errmsg set
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_rootdse_done] (0x2000): Got rootdse
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 84351 (int: 84351)
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_kinit_send]
> (0x0400): Attempting kinit (default, host/kwtpocpbis01.solaris.local,
> SOLARIS.LOCAL, 86400)
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_kinit_next_kdc]
> (0x1000): Resolving next KDC for service IPA
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [get_server_status]
> (0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name resolved'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
> seconds
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [get_server_status]
> (0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name resolved'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [be_resolve_server_process] (0x1000): Saving the first resolved server
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [be_resolve_server_process] (0x0200): Found address for server
> kwtpocpbis01.solaris.local: [172.16.107.244] TTL 7200
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT...
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [create_tgt_req_send_buffer] (0x0400): buffer size: 68
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [child_handler_setup]
> (0x2000): Setting up signal handler up for pid [16425]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [child_handler_setup]
> (0x2000): Signal handler set up for pid [16425]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_process_result]
> (0x2000): Trace: sh[0x7f6b7d2c6140], connected[1], ops[(nil)],
> ldap[0x7f6b7d265a00]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_process_result]
> (0x2000): Trace: ldap_result found nothing!
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [write_pipe_handler]
> (0x0400): All data has been sent!
>
> ==> ldap_child.log <==
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [main] (0x0400):
> ldap_child started.
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [main] (0x2000):
> context initialized
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [unpack_buffer]
> (0x1000): total buffer size: 68
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [unpack_buffer]
> (0x1000): realm_str size: 13
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [unpack_buffer]
> (0x1000): got realm_str: SOLARIS.LOCAL
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [unpack_buffer]
> (0x1000): princ_str size: 31
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [unpack_buffer]
> (0x1000): got princ_str: host/kwtpocpbis01.solaris.local
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [unpack_buffer]
> (0x1000): keytab_name size: 0
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [unpack_buffer]
> (0x1000): lifetime: 86400
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [unpack_buffer]
> (0x0200): Will run as [0][0].
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [privileged_krb5_setup] (0x2000): Kerberos context initialized
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [main] (0x2000):
> Kerberos context initialized
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [become_user]
> (0x0200): Trying to become user [0][0].
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [become_user]
> (0x0200): Already user [0].
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [main] (0x2000):
> Running as [0][0].
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [main] (0x2000):
> getting TGT sync
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [ldap_child_get_tgt_sync] (0x2000): got realm_name: [SOLARIS.LOCAL]
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [ldap_child_get_tgt_sync] (0x0100): Principal name is:
> [host/kwtpocpbis01.solaris.local at SOLARIS.LOCAL]
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [ldap_child_get_tgt_sync] (0x0100): Using keytab [MEMORY:/etc/krb5.keytab]
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.524474: Getting
> initial credentials for host/kwtpocpbis01.solaris.local at SOLARIS.LOCAL
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.526526: Looked up
> etypes in keytab: rc4-hmac, des3-cbc-sha1, aes128-cts, aes256-cts
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.526597: Sending
> request (196 bytes) to SOLARIS.LOCAL
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.526803: Initiating
> TCP connection to stream 172.16.107.244:88
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.526892: Sending TCP
> request to stream 172.16.107.244:88
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.528813: Received
> answer (371 bytes) from stream 172.16.107.244:88
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.528846: Terminating
> TCP connection to stream 172.16.107.244:88
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.528895: Response was
> from master KDC
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.528937: Received
> error from KDC: -1765328359/Additional pre-authentication required
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.528977: Processing
> preauth types: 136, 19, 2, 133
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.529008: Selected
> etype info: etype aes256-cts, salt "jUdxx&tm\3}.mh_[", params ""
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.529023: Received
> cookie: MIT
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.529056: Retrieving
> host/kwtpocpbis01.solaris.local at SOLARIS.LOCAL from
> MEMORY:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.529088: AS key
> obtained for encrypted timestamp: aes256-cts/445E
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.529148: Encrypted
> timestamp (for 1426592010.528836): plain
> 301AA011180F32303135303331373131333333305AA10502030811C4, encrypted
> 98625FC80F84BE6C287E596D254D3862CE1A8938418E92A91224BB349985496C8AD8D7161D736951B4C3907B8F4CB964577C28F6C3B81708
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.529173: Preauth
> module encrypted_timestamp (2) (real) returned: 0/Success
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.529195: Produced
> preauth for next request: 133, 2
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.529216: Sending
> request (291 bytes) to SOLARIS.LOCAL
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.529248: Initiating
> TCP connection to stream 172.16.107.244:88
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.529293: Sending TCP
> request to stream 172.16.107.244:88
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.535622: Received
> answer (201 bytes) from stream 172.16.107.244:88
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.535657: Terminating
> TCP connection to stream 172.16.107.244:88
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.535705: Response was
> from master KDC
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [sss_child_krb5_trace_cb] (0x4000): [16425] 1426592010.535733: Received
> error from KDC: -1765328353/Decrypt integrity check failed
>
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]]
> [ldap_child_get_tgt_sync] (0x0010): Failed to init credentials: Decrypt
> integrity check failed
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [main] (0x0020):
> ldap_child_get_tgt_sync failed.
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [prepare_response]
> (0x0400): Building response for result [-1765328353]
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [pack_buffer]
> (0x2000): response size: 50
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [pack_buffer]
> (0x1000): result [14] krberr [-1765328353] msgsize [30] msg [Decrypt
> integrity check failed]
> (Tue Mar 17 14:33:30 2015) [[sssd[ldap_child[16425]]]] [main] (0x0400):
> ldap_child completed successfully
>
> ==> sssd_solaris.local.log <==
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [child_sig_handler]
> (0x1000): Waiting for child [16425].
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [child_sig_handler]
> (0x0100): child [16425] finished successfully.
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [read_pipe_handler]
> (0x0400): EOF received, client finished
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_get_tgt_recv]
> (0x0400): Child responded: 14 [Decrypt integrity check failed], expired on
> [0]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_kinit_done]
> (0x0100): Could not get TGT: 14 [Bad address]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_cli_kinit_done]
> (0x0400): Cannot get a TGT: ret [1432158219](Authentication Failed)
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
> (0x0100): Marking port 0 of server 'kwtpocpbis01.solaris.local' as 'not
> working'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
> (0x0400): Marking port 0 of duplicate server 'kwtpocpbis01.solaris.local'
> as 'not working'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_handle_release]
> (0x2000): Trace: sh[0x7f6b7d2c6140], connected[1], ops[(nil)],
> ldap[0x7f6b7d265a00], destructor_lock[0], release_memory[0]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [remove_connection_callback] (0x4000): Successfully removed connection
> callback.
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [check_online_callback] (0x0100): Backend returned: (3, 0, <NULL>)
> [Internal Error (Success)]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [set_srv_data_status]
> (0x0100): Marking SRV lookup of service 'gc_infra.com' as 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
> (0x0100): Marking port 0 of server '(no name)' as 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [set_srv_data_status]
> (0x0100): Marking SRV lookup of service 'infra.com' as 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
> (0x0100): Marking port 0 of server '(no name)' as 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [set_server_common_status] (0x0100): Marking server
> 'kwtpocpbis01.solaris.local' as 'name not resolved'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
> (0x0100): Marking port 0 of server 'kwtpocpbis01.solaris.local' as 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [fo_set_port_status]
> (0x0400): Marking port 0 of duplicate server 'kwtpocpbis01.solaris.local'
> as 'neutral'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [be_ptask_disable]
> (0x0400): Task [Check if online (periodic)]: disabling task
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [be_run_online_cb]
> (0x0080): Going online. Running callbacks.
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [ipa_subdom_reset_timeouts_cb] (0x4000): Resetting last_refreshed and
> disabled_until.
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_sudo_schedule_refresh] (0x0400): Full refresh scheduled at: 1426592010
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_sudo_full_refresh_send] (0x0400): Issuing a full refresh of sudo rules
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_id_op_connect_step] (0x4000): beginning to connect
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [get_server_status]
> (0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name not
> resolved'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
> seconds
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [get_server_status]
> (0x1000): Status of server 'kwtpocpbis01.solaris.local' is 'name not
> resolved'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [resolv_is_address]
> (0x4000): [kwtpocpbis01.solaris.local] does not look like an IP address
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [resolv_gethostbyname_step] (0x2000): Querying files
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of
> 'kwtpocpbis01.solaris.local' in files
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [set_server_common_status] (0x0100): Marking server
> 'kwtpocpbis01.solaris.local' as 'resolving name'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [set_server_common_status] (0x0100): Marking server
> 'kwtpocpbis01.solaris.local' as 'name resolved'
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [be_resolve_server_process] (0x1000): Saving the first resolved server
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [be_resolve_server_process] (0x0200): Found address for server
> kwtpocpbis01.solaris.local: [172.16.107.244] TTL 7200
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sss_ldap_init_send]
> (0x4000): Using file descriptor [22] for LDAP connection.
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sss_ldap_init_send]
> (0x0400): Setting 6 seconds timeout for connecting
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to
> [ldap://kwtpocpbis01.solaris.local:389/??base] with fd [22].
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_rootdse_send] (0x4000): Getting rootdse
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [sdap_print_server]
> (0x2000): Searching 172.16.107.244
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
> [(objectclass=*)][].
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs:
> [supportedLDAPVersion]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs:
> [supportedSASLMechanisms]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs:
> [domainControllerFunctionality]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs:
> [defaultNamingContext]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x1000): Requesting attrs:
> [highestCommittedUSN]
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]] [ad_online_cb]
> (0x0400): The AD provider is online
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [sdap_id_op_connect_step] (0x4000): waiting for connection to complete
> (Tue Mar 17 14:33:30 2015) [sssd[be[solaris.local]]]
> [delayed_online_authentication_callback] (0x0200): Backend is online,
> starting delayed online authentication.
>
>
> On Tue, Mar 17, 2015 at 2:23 PM, Ben .T.George <bentech4you at gmail.com>
> wrote:
>
>> HI
>>
>> i have changed like this:
>>
>> [root at kwtpocpbis01 yum.repos.d]# more /etc/sssd/sssd.conf
>> [domain/solaris.local]
>> cache_credentials = True
>> krb5_store_password_if_offline = True
>> ipa_domain = solaris.local
>> id_provider = ipa
>> auth_provider = ipa
>> access_provider = ipa
>> ipa_hostname = kwtpocpbis01.solaris.local
>> chpass_provider = ipa
>> ipa_server = kwtpocpbis01.solaris.local
>> ipa_server_mode = True
>> ldap_tls_cacert = /etc/ipa/ca.crt
>> debug_level = 10
>> [sssd]
>> services = nss, sudo, pam, ssh
>> config_file_version = 2
>> debug_level = 5
>> domains = solaris.local
>> [nss]
>> homedir_substring = /home
>> debug_level = 6
>>
>> [pam]
>> debug_level = 10
>> [sudo]
>> debug_level = 5
>> [autofs]
>> debug_level = 5
>> [ssh]
>> debug_level = 5
>> [pac]
>> debug_level = 5
>> [ifp]
>>
>>
>> but sssd.log looks same.
>>
>> (Tue Mar 17 14:23:13 2015) [sssd] [ping_check] (0x0100): Service pam
>> replied to ping
>> (Tue Mar 17 14:23:23 2015) [sssd] [service_send_ping] (0x0100): Pinging
>> solaris.local
>> (Tue Mar 17 14:23:23 2015) [sssd] [service_send_ping] (0x0100): Pinging
>> nss
>> (Tue Mar 17 14:23:23 2015) [sssd] [service_send_ping] (0x0100): Pinging
>> sudo
>> (Tue Mar 17 14:23:23 2015) [sssd] [service_send_ping] (0x0100): Pinging
>> pam
>> (Tue Mar 17 14:23:23 2015) [sssd] [service_send_ping] (0x0100): Pinging
>> ssh
>> (Tue Mar 17 14:23:23 2015) [sssd] [service_send_ping] (0x0100): Pinging
>> pac
>> (Tue Mar 17 14:23:23 2015) [sssd] [ping_check] (0x0100): Service sudo
>> replied to ping
>> (Tue Mar 17 14:23:23 2015) [sssd] [ping_check] (0x0100): Service ssh
>> replied to ping
>> (Tue Mar 17 14:23:23 2015) [sssd] [ping_check] (0x0100): Service pam
>> replied to ping
>> (Tue Mar 17 14:23:23 2015) [sssd] [ping_check] (0x0100): Service
>> solaris.local replied to ping
>> (Tue Mar 17 14:23:23 2015) [sssd] [ping_check] (0x0100): Service pac
>> replied to ping
>> (Tue Mar 17 14:23:23 2015) [sssd] [ping_check] (0x0100): Service nss
>> replied to ping
>>
>> On Tue, Mar 17, 2015 at 1:27 PM, Jakub Hrozek <jhrozek at redhat.com> wrote:
>>
>>> On Tue, Mar 17, 2015 at 12:57:27PM +0300, Ben .T.George wrote:
>>> > HI
>>> >
>>> > i have enabled debug
>>> >
>>> > here is my sssd.conf
>>> >
>>> > [root at kwtpocpbis01 ~]# cat /etc/sssd/sssd.conf
>>> > [domain/solaris.local]
>>> >
>>> > cache_credentials = True
>>> > krb5_store_password_if_offline = True
>>> > ipa_domain = solaris.local
>>> > id_provider = ipa
>>> > auth_provider = ipa
>>> > access_provider = ipa
>>> > ipa_hostname = kwtpocpbis01.solaris.local
>>> > chpass_provider = ipa
>>> > ipa_server = kwtpocpbis01.solaris.local
>>> > ipa_server_mode = True
>>> > ldap_tls_cacert = /etc/ipa/ca.crt
>>>
>>> Please also add debug_level to this section, not just [sssd] and [nss]
>>>
>>>
>>> > [sssd]
>>> > services = nss, sudo, pam, ssh
>>> > config_file_version = 2
>>> >
>>> > domains = solaris.local
>>> > debug_level = 6
>>> > [nss]
>>> > homedir_substring = /home
>>> > debug_level = 6
>>> >
>>> > [pam]
>>> >
>>> > [sudo]
>>> >
>>> > [autofs]
>>> >
>>> > [ssh]
>>> >
>>> > [pac]
>>> >
>>> > [ifp]
>>>
>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20150317/73f02699/attachment.htm>