Attachment 1405727 Details for Bug 1553056 – sssd_kcm log file with debug_level = 10

sssd_kcm log file with debug_level = 10

sssd_kcm.log (text/plain), 10.62 KB, created by Lorenzo Dalrio on 2018-03-08 07:41:13 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Lorenzo Dalrio

Created: 2018-03-08 07:41:13 UTC

Size: 10.62 KB

patch

obsolete

>(Thu Mar  8 08:27:06:449145 2018) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55872dc1a100
>
>(Thu Mar  8 08:27:06:449197 2018) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55872dc1a1c0
>
>(Thu Mar  8 08:27:06:449207 2018) [sssd[kcm]] [ldb] (0x4000): Running timer event 0x55872dc1a100 "ltdb_callback"
>
>(Thu Mar  8 08:27:06:449225 2018) [sssd[kcm]] [ldb] (0x4000): Destroying timer event 0x55872dc1a1c0 "ltdb_timeout"
>
>(Thu Mar  8 08:27:06:449233 2018) [sssd[kcm]] [ldb] (0x4000): Ending timer event 0x55872dc1a100 "ltdb_callback"
>
>(Thu Mar  8 08:27:06:449535 2018) [sssd[kcm]] [server_setup] (0x0400): CONFDB: /var/lib/sss/db/config.ldb
>(Thu Mar  8 08:27:06:449571 2018) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55872dc1c360
>
>(Thu Mar  8 08:27:06:449579 2018) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55872dc1c420
>
>(Thu Mar  8 08:27:06:449586 2018) [sssd[kcm]] [ldb] (0x4000): Running timer event 0x55872dc1c360 "ltdb_callback"
>
>(Thu Mar  8 08:27:06:449601 2018) [sssd[kcm]] [ldb] (0x4000): Destroying timer event 0x55872dc1c420 "ltdb_timeout"
>
>(Thu Mar  8 08:27:06:449609 2018) [sssd[kcm]] [ldb] (0x4000): Ending timer event 0x55872dc1c360 "ltdb_callback"
>
>(Thu Mar  8 08:27:06:449627 2018) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55872dc1c2a0
>
>(Thu Mar  8 08:27:06:449634 2018) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55872dc1c420
>
>(Thu Mar  8 08:27:06:449641 2018) [sssd[kcm]] [ldb] (0x4000): Running timer event 0x55872dc1c2a0 "ltdb_callback"
>
>(Thu Mar  8 08:27:06:449652 2018) [sssd[kcm]] [ldb] (0x4000): Destroying timer event 0x55872dc1c420 "ltdb_timeout"
>
>(Thu Mar  8 08:27:06:449660 2018) [sssd[kcm]] [ldb] (0x4000): Ending timer event 0x55872dc1c2a0 "ltdb_callback"
>
>(Thu Mar  8 08:27:06:449676 2018) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55872dc1c360
>
>(Thu Mar  8 08:27:06:449683 2018) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55872dc1c420
>
>(Thu Mar  8 08:27:06:449690 2018) [sssd[kcm]] [ldb] (0x4000): Running timer event 0x55872dc1c360 "ltdb_callback"
>
>(Thu Mar  8 08:27:06:449701 2018) [sssd[kcm]] [ldb] (0x4000): Destroying timer event 0x55872dc1c420 "ltdb_timeout"
>
>(Thu Mar  8 08:27:06:449709 2018) [sssd[kcm]] [ldb] (0x4000): Ending timer event 0x55872dc1c360 "ltdb_callback"
>
>(Thu Mar  8 08:27:06:449725 2018) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55872dc1c2a0
>
>(Thu Mar  8 08:27:06:449732 2018) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55872dc1c420
>
>(Thu Mar  8 08:27:06:449739 2018) [sssd[kcm]] [ldb] (0x4000): Running timer event 0x55872dc1c2a0 "ltdb_callback"
>
>(Thu Mar  8 08:27:06:449750 2018) [sssd[kcm]] [ldb] (0x4000): Destroying timer event 0x55872dc1c420 "ltdb_timeout"
>
>(Thu Mar  8 08:27:06:449758 2018) [sssd[kcm]] [ldb] (0x4000): Ending timer event 0x55872dc1c2a0 "ltdb_callback"
>
>(Thu Mar  8 08:27:06:449772 2018) [sssd[kcm]] [kcm_get_ccdb_be] (0x0100): KCM database type: secrets
>(Thu Mar  8 08:27:06:449799 2018) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55872dc1c360
>
>(Thu Mar  8 08:27:06:449807 2018) [sssd[kcm]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55872dc1c420
>
>(Thu Mar  8 08:27:06:449814 2018) [sssd[kcm]] [ldb] (0x4000): Running timer event 0x55872dc1c360 "ltdb_callback"
>
>(Thu Mar  8 08:27:06:449830 2018) [sssd[kcm]] [ldb] (0x4000): Destroying timer event 0x55872dc1c420 "ltdb_timeout"
>
>(Thu Mar  8 08:27:06:449843 2018) [sssd[kcm]] [ldb] (0x4000): Ending timer event 0x55872dc1c360 "ltdb_callback"
>
>(Thu Mar  8 08:27:06:449861 2018) [sssd[kcm]] [schedule_responder_idle_timer] (0x2000): Re-scheduling the idle timeout for the responder [0x55872dc1c0f0]
>(Thu Mar  8 08:27:06:449886 2018) [sssd[kcm]] [setup_responder_idle_timer] (0x2000): Setting up the idle timeout for the responder [0x55872dc1c0f0]
>(Thu Mar  8 08:27:06:449902 2018) [sssd[kcm]] [kcm_ccdb_init] (0x0200): KCM back end: sssd-secrets
>(Thu Mar  8 08:27:06:452639 2018) [sssd[kcm]] [responder_set_fd_limit] (0x0100): Maximum file descriptors set to [2048]
>(Thu Mar  8 08:27:06:452688 2018) [sssd[kcm]] [kcm_process_init] (0x0400): KCM Initialization complete
>(Thu Mar  8 08:27:06:452747 2018) [sssd[kcm]] [get_client_cred] (0x4000): Client creds: euid[1000] egid[1000] pid[7246].
>(Thu Mar  8 08:27:06:452852 2018) [sssd[kcm]] [setup_client_idle_timer] (0x4000): Idle timer re-set for client [0x55872dc19d20][12]
>(Thu Mar  8 08:27:06:452904 2018) [sssd[kcm]] [accept_fd_handler] (0x0400): Client connected!
>(Thu Mar  8 08:27:06:452931 2018) [sssd[kcm]] [kcm_input_parse] (0x1000): Received message with length 4
>(Thu Mar  8 08:27:06:452942 2018) [sssd[kcm]] [kcm_get_opt] (0x2000): The client requested operation 20
>(Thu Mar  8 08:27:06:452956 2018) [sssd[kcm]] [kcm_cmd_send] (0x0400): KCM operation GET_DEFAULT_CACHE
>(Thu Mar  8 08:27:06:452966 2018) [sssd[kcm]] [kcm_cmd_send] (0x1000): 0 bytes on KCM input
>(Thu Mar  8 08:27:06:453134 2018) [sssd[kcm]] [kcm_op_queue_send] (0x0200): Adding request by 1000 to the wait queue
>(Thu Mar  8 08:27:06:453152 2018) [sssd[kcm]] [kcm_op_queue_get] (0x1000): No existing queue for this ID
>(Thu Mar  8 08:27:06:453163 2018) [sssd[kcm]] [kcm_op_queue_send] (0x1000): Queue was empty, running the request immediately
>(Thu Mar  8 08:27:06:453176 2018) [sssd[kcm]] [kcm_op_get_default_ccache_send] (0x1000): Getting client's default ccache
>(Thu Mar  8 08:27:06:453186 2018) [sssd[kcm]] [ccdb_sec_get_default_send] (0x2000): Getting the default ccache
>(Thu Mar  8 08:27:06:453221 2018) [sssd[kcm]] [tcurl_request_send] (0x0400): Sending TCURL request for http://localhost/kcm/persistent/1000/default, at socket /var/run/secrets.socket
>(Thu Mar  8 08:27:06:453237 2018) [sssd[kcm]] [schedule_fd_processing] (0x2000): timeout_ms: 0
>(Thu Mar  8 08:27:06:453400 2018) [sssd[kcm]] [handle_socket] (0x2000): Activity on curl socket 13 socket data (nil)
>(Thu Mar  8 08:27:06:453422 2018) [sssd[kcm]] [schedule_fd_processing] (0x2000): timeout_ms: 0
>(Thu Mar  8 08:27:06:453434 2018) [sssd[kcm]] [check_curl_timeouts] (0x4000): Still tracking 1 outstanding requests
>(Thu Mar  8 08:27:06:453450 2018) [sssd[kcm]] [schedule_fd_processing] (0x2000): timeout_ms: 199
>(Thu Mar  8 08:27:06:453460 2018) [sssd[kcm]] [check_curl_timeouts] (0x4000): Still tracking 1 outstanding requests
>(Thu Mar  8 08:27:06:496687 2018) [sssd[kcm]] [tcurl_write_data] (0x2000): ---> begin libcurl data
>(Thu Mar  8 08:27:06:496711 2018) [sssd[kcm]] [tcurl_write_data] (0x2000): 47a55a0d-ccff-422b-a468-999889877897
>(Thu Mar  8 08:27:06:496719 2018) [sssd[kcm]] [tcurl_write_data] (0x2000): <--- end libcurl data
>(Thu Mar  8 08:27:06:496733 2018) [sssd[kcm]] [handle_socket] (0x2000): Activity on curl socket 13 socket data 0x55872dc18bc0
>(Thu Mar  8 08:27:06:496745 2018) [sssd[kcm]] [handle_curlmsg_done] (0x0400): Handled http://localhost/kcm/persistent/1000/default
>(Thu Mar  8 08:27:06:496757 2018) [sssd[kcm]] [tcurl_request_done] (0x0400): TCURL request finished [0]: Success
>(Thu Mar  8 08:27:06:496764 2018) [sssd[kcm]] [schedule_fd_processing] (0x2000): timeout_ms: -1
>(Thu Mar  8 08:27:06:496771 2018) [sssd[kcm]] [check_curl_timeouts] (0x4000): Still tracking 0 outstanding requests
>(Thu Mar  8 08:27:06:496786 2018) [sssd[kcm]] [ccdb_sec_get_default_done] (0x2000): Got the default ccache
>(Thu Mar  8 08:27:06:496798 2018) [sssd[kcm]] [ccdb_sec_name_by_uuid_send] (0x2000): Translating UUID to name
>(Thu Mar  8 08:27:06:496805 2018) [sssd[kcm]] [sec_list_send] (0x2000): Listing all ccaches in the secrets store
>(Thu Mar  8 08:27:06:496817 2018) [sssd[kcm]] [tcurl_request_send] (0x0400): Sending TCURL request for http://localhost/kcm/persistent/1000/ccache/, at socket /var/run/secrets.socket
>(Thu Mar  8 08:27:06:496826 2018) [sssd[kcm]] [schedule_fd_processing] (0x2000): timeout_ms: 0
>(Thu Mar  8 08:27:06:496880 2018) [sssd[kcm]] [handle_socket] (0x2000): Activity on curl socket 13 socket data (nil)
>(Thu Mar  8 08:27:06:496894 2018) [sssd[kcm]] [schedule_fd_processing] (0x2000): timeout_ms: 0
>(Thu Mar  8 08:27:06:496901 2018) [sssd[kcm]] [check_curl_timeouts] (0x4000): Still tracking 1 outstanding requests
>(Thu Mar  8 08:27:06:496918 2018) [sssd[kcm]] [schedule_fd_processing] (0x2000): timeout_ms: 5000
>(Thu Mar  8 08:27:06:496925 2018) [sssd[kcm]] [check_curl_timeouts] (0x4000): Still tracking 1 outstanding requests
>(Thu Mar  8 08:27:06:497371 2018) [sssd[kcm]] [tcurl_write_data] (0x2000): ---> begin libcurl data
>(Thu Mar  8 08:27:06:497383 2018) [sssd[kcm]] [tcurl_write_data] (0x2000): [
>    "04c98dfa-0d22-455a-acd2-4ce8647df747-1000"
>]
>(Thu Mar  8 08:27:06:497389 2018) [sssd[kcm]] [tcurl_write_data] (0x2000): <--- end libcurl data
>(Thu Mar  8 08:27:06:497398 2018) [sssd[kcm]] [handle_socket] (0x2000): Activity on curl socket 13 socket data 0x55872dc18bc0
>(Thu Mar  8 08:27:06:497408 2018) [sssd[kcm]] [handle_curlmsg_done] (0x0400): Handled http://localhost/kcm/persistent/1000/ccache/
>(Thu Mar  8 08:27:06:497417 2018) [sssd[kcm]] [tcurl_request_done] (0x0400): TCURL request finished [0]: Success
>(Thu Mar  8 08:27:06:497424 2018) [sssd[kcm]] [schedule_fd_processing] (0x2000): timeout_ms: -1
>(Thu Mar  8 08:27:06:497430 2018) [sssd[kcm]] [check_curl_timeouts] (0x4000): Still tracking 0 outstanding requests
>(Thu Mar  8 08:27:06:497441 2018) [sssd[kcm]] [sec_list_done] (0x2000): Found 0 items
>(Thu Mar  8 08:27:06:497452 2018) [sssd[kcm]] [sec_list_done] (0x2000): list done
>(Thu Mar  8 08:27:06:497461 2018) [sssd[kcm]] [ccdb_sec_name_by_uuid_done] (0x2000): No such UUID
>(Thu Mar  8 08:27:06:497468 2018) [sssd[kcm]] [kcm_ccdb_name_by_uuid_done] (0x0040): Failed to resolve cache by UUID [1432158218]: No credentials available
>(Thu Mar  8 08:27:06:497475 2018) [sssd[kcm]] [kcm_op_get_default_ccache_byuuid_done] (0x0040): Cannot get ccahe by UUID [1432158218]: No credentials available
>(Thu Mar  8 08:27:06:497482 2018) [sssd[kcm]] [kcm_cmd_done] (0x0040): op receive function failed [1432158218]: No credentials available
>(Thu Mar  8 08:27:06:497532 2018) [sssd[kcm]] [kcm_cmd_request_done] (0x0040): KCM operation failed [1432158218]: No credentials available
>(Thu Mar  8 08:27:06:497544 2018) [sssd[kcm]] [kcm_reply_error] (0x0040): KCM operation returs failure [1432158218]: No credentials available
>(Thu Mar  8 08:27:06:497551 2018) [sssd[kcm]] [kcm_failbuf_construct] (0x1000): Sent reply with error -1765328243
>(Thu Mar  8 08:27:06:497561 2018) [sssd[kcm]] [queue_removal_cb] (0x0200): Removed queue for 1000 
>(Thu Mar  8 08:27:06:497579 2018) [sssd[kcm]] [kcm_send] (0x2000): All data sent!
>(Thu Mar  8 08:27:06:497601 2018) [sssd[kcm]] [kcm_recv] (0x0010): Failed to receive data (104, Connection reset by peer), aborting client
>(Thu Mar  8 08:27:06:497623 2018) [sssd[kcm]] [client_close_fn] (0x2000): Terminated client [0x55872dc19d20][12]

Actions: View

Attachments on bug 1553056: 1405727 | 1405728 | 1448024 | 1448025 | 1448026