On Tue, May 01, 2018 at 01:53:48PM +0200, cedric hottier wrote:
> Dear sssd users,
>
> I observe that at each sssd start, the credentials cache is cleared. Is it
> an expected behavior ?
> If yes, is there a parameter to make this caching permanent (or at least
> not erased at each sssd restart ).
> My issue is that If I reboot my laptop without connection to my KDC, I am
> not able to log due to [sysdb_cache_auth] cached credentials not available.
>
> here is my config : Debian testing / SSD version : 1.16.1
>
> /etc/sssd/sssd.conf :
> [sssd]
> services = nss, pam, ifp
> domains = ECCM.LAN
>
> [pam]
> pam_verbosity = 2
> offline_credentials_expiration = 0
>
> /etc/sssd/conf.d/01_ECCM_LAN.conf
> [domain/ECCM.LAN]
> debug_level = 10
> id_provider = files
I'm afraid this is a known bug with id_provider=files. I was looking
into fixing this last week, but I don't have a patch yet.
In the meantime, you can use:
id_provider=proxy
proxy_lib_name=files
I think that should work in the meantime..
> auth_provider = krb5
> krb5_server = DebianCubox.eccm.lan
> krb5_realm = ECCM.LAN
> krb5_validate = true
> krb5_ccachedir = /var/tmp
> krb5_keytab = /etc/krb5.keytab
> krb5_store_password_if_offline = true
>
> cache_credentials = true
>
> After a fresh reboot, I am able to log in only if the krb5_server is
> available.
> As long as I do not restart the sssd daemon, I am able to log in.
>
> The credentials caching seems to work properly as I see
> " Authenticated with cache credentials " at each TTY console just before
> the usual loggin message.
>
> But If restart the sssd daemon while disconnected from the network, I am
> not able to log in anymore. The credentials cache seems to have been
> cleared.
>
> Here is the /var/log/sssd/krb5_child.log
>
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [main] (0x0400):
> krb5_child started.
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [unpack_buffer]
> (0x1000): total buffer size: [128]
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [unpack_buffer]
> (0x0100): cmd [241] uid [1000] gid [1000] validate [true] enterprise
> principal [false] offline [true] UPN [ced...@eccm.lan]
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [unpack_buffer]
> (0x2000): No old ccache
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [unpack_buffer]
> (0x0100): ccname: [FILE:/var/tmp/krb5cc_1000_XXXXXX] old_ccname: [not set]
> keytab: [/etc/krb5.keytab]
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [check_use_fast]
> (0x0100): Not using FAST.
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]]
> [k5c_precreate_ccache] (0x4000): Recreating ccache
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]]
> [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [become_user]
> (0x0200): Trying to become user [1000][1000].
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [main] (0x2000):
> Running as [1000][1000].
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [become_user]
> (0x0200): Trying to become user [1000][1000].
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [become_user]
> (0x0200): Already user [1000].
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [k5c_setup] (0x2000):
> Running as [1000][1000].
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]]
> [set_lifetime_options] (0x0100): No specific renewable lifetime requested.
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]]
> [set_lifetime_options] (0x0100): No specific lifetime requested.
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [main] (0x0400): Will
> perform offline auth
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [create_empty_ccache]
> (0x1000): Creating empty ccache
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [create_empty_cred]
> (0x2000): Created empty krb5_creds.
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [create_ccache]
> (0x4000): Initializing ccache of type [FILE]
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [create_ccache]
> (0x4000): returning: 0
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [k5c_send_data]
> (0x0200): Received error code 0
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]]
> [pack_response_packet] (0x2000): response packet size: [56]
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [k5c_send_data]
> (0x4000): Response sent.
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [main] (0x0400):
> krb5_child completed successfully
>
> On /var/log/sssd/sssd_ECCM_LAN.log :
>
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [sbus_dispatch] (0x4000):
> dbus conn: 0x560ea04b4be0
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [sbus_dispatch] (0x4000):
> Dispatching.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [sbus_message_handler]
> (0x2000): Received SBUS method
> org.freedesktop.sssd.dataprovider.getAccountInfo on path
> /org/freedesktop/sssd/dataprovider
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [sbus_get_sender_id_send]
> (0x2000): Not a sysbus message, quit
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]]
> [dp_get_account_info_handler] (0x0200): Got request for
> [0x3][BE_REQ_INITGROUPS][name=files_initgr_request]
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [sss_domain_get_state]
> (0x1000): Domain ECCM.LAN is Active
>
> ...
>
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_attach_req] (0x0400):
> DP Request [Initgroups #2]: New request. Flags [0x0001].
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_attach_req] (0x0400):
> Number of active DP request: 1
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [sss_domain_get_state]
> (0x1000): Domain ECCM.LAN is Active
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]]
> [files_account_info_handler_send] (0x1000): The files domain no longer
> needs an update
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_req_done] (0x0400): DP
> Request [Initgroups #2]: Request handler finished [0]: Succès
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [_dp_req_recv] (0x0400): DP
> Request [Initgroups #2]: Receiving request data.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_req_reply_list_success]
> (0x0400): DP Request [Initgroups #2]: Finished. Success.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_req_reply_std]
> (0x1000): DP Request [Initgroups #2]: Returning [Success]: 0,0,Success
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_table_value_destructor]
> (0x0400): Removing [0:1:0x0001:3::ECCM.LAN:name=files_initgr_request] from
> reply table
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_req_destructor]
> (0x0400): DP Request [Initgroups #2]: Request removed.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_req_destructor]
> (0x0400): Number of active DP request: 0
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [sbus_dispatch] (0x4000):
> dbus conn: 0x560ea04b4be0
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [sbus_dispatch] (0x4000):
> Dispatching.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [sbus_message_handler]
> (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.pamHandler
> on path /org/freedesktop/sssd/dataprovider
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [sbus_get_sender_id_send]
> (0x2000): Not a sysbus message, quit
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_pam_handler] (0x0100):
> Got request with the following data
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [pam_print_data] (0x0100):
> command: SSS_PAM_AUTHENTICATE
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [pam_print_data] (0x0100):
> domain: ECCM.LAN
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [pam_print_data] (0x0100):
> user: ced...@eccm.lan
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [pam_print_data] (0x0100):
> service: login
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [pam_print_data] (0x0100):
> tty: /dev/tty2
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [pam_print_data] (0x0100):
> ruser:
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [pam_print_data] (0x0100):
> rhost:
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [pam_print_data] (0x0100):
> authtok type: 1
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [pam_print_data] (0x0100):
> newauthtok type: 0
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [pam_print_data] (0x0100):
> priv: 1
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [pam_print_data] (0x0100):
> cli_pid: 8940
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [pam_print_data] (0x0100):
> logon name: not set
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_attach_req] (0x0400):
> DP Request [PAM Authenticate #3]: New request. Flags [0000].
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_attach_req] (0x0400):
> Number of active DP request: 1
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [sss_domain_get_state]
> (0x1000): Domain ECCM.LAN is Active
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [krb5_auth_queue_send]
> (0x1000): Wait queue of user [ced...@eccm.lan] is empty, running request
> [0x560ea0455cc0] immediately.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [krb5_setup] (0x4000): No
> mapping for: ced...@eccm.lan
> ...
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [krb5_get_simple_upn]
> (0x4000): Using simple UPN [ced...@eccm.lan].
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [check_ccache_re] (0x1000):
> Ccache directory name [/var/tmp] does not contain illegal patterns.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [check_ccache_re] (0x1000):
> Ccache directory name [FILE:/var/tmp/krb5cc_1000_XXXXXX] does not contain
> illegal patterns.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]]
> [krb5_auth_prepare_ccache_name] (0x1000): No ccache file for user
> [ced...@eccm.lan] found.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [fo_resolve_service_send]
> (0x0100): Trying to resolve service 'KERBEROS'
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [get_server_status]
> (0x1000): Status of server 'DebianCubox.eccm.lan' is 'name not resolved'
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [get_port_status] (0x1000):
> Port status of port 0 for server 'DebianCubox.eccm.lan' is 'neutral'
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]]
> [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
> seconds
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [get_server_status]
> (0x1000): Status of server 'DebianCubox.eccm.lan' is 'name not resolved'
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [resolv_is_address]
> (0x4000): [DebianCubox.eccm.lan] does not look like an IP address
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [resolv_gethostbyname_step]
> (0x2000): Querying files
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]]
> [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of
> 'DebianCubox.eccm.lan' in files
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [set_server_common_status]
> (0x0100): Marking server 'DebianCubox.eccm.lan' as 'resolving name'
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [resolv_gethostbyname_step]
> (0x2000): Querying files
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]]
> [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record
> of 'DebianCubox.eccm.lan' in files
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [resolv_gethostbyname_next]
> (0x0200): No more address families to retry
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [resolv_gethostbyname_step]
> (0x2000): Querying DNS
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]]
> [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of
> 'DebianCubox.eccm.lan' in DNS
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [schedule_request_timeout]
> (0x2000): Scheduling a timeout of 6 seconds
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [schedule_timeout_watcher]
> (0x2000): Scheduling DNS timeout watcher
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]]
> [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [request_watch_destructor]
> (0x0400): Deleting request watch
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [resolv_gethostbyname_done]
> (0x0040): querying hosts database failed [5]: Erreur d'entrée/sortie
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [fo_resolve_service_done]
> (0x0020): Failed to resolve server 'DebianCubox.eccm.lan': Could not
> contact DNS servers
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [set_server_common_status]
> (0x0100): Marking server 'DebianCubox.eccm.lan' as 'not working'
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [be_resolve_server_process]
> (0x0080): Couldn't resolve server (DebianCubox.eccm.lan), resolver returned
> [5]: Erreur d'entrée/sortie
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [be_resolve_server_process]
> (0x1000): Trying with the next one!
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [fo_resolve_service_send]
> (0x0100): Trying to resolve service 'KERBEROS'
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [get_server_status]
> (0x1000): Status of server 'DebianCubox.eccm.lan' is 'not working'
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [get_server_status]
> (0x1000): Status of server 'DebianCubox.eccm.lan' is 'not working'
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [fo_resolve_service_send]
> (0x0020): No available servers for service 'KERBEROS'
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [be_resolve_server_done]
> (0x1000): Server resolution failed: [5]: Erreur d'entrée/sortie
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [be_mark_dom_offline]
> (0x1000): Marking back end offline
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [be_mark_offline] (0x2000):
> Going offline!
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [be_mark_offline] (0x2000):
> Initialize check_if_online_ptask.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [ldb] (0x4000): Added timed
> event "ltdb_callback": 0x560ea048ceb0
> ...
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [be_ptask_create] (0x0400):
> Periodic task [Check if online (periodic)] was created
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [be_ptask_schedule]
> (0x0400): Task [Check if online (periodic)]: scheduling task 73 seconds
> from now [1525171017]
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [be_run_offline_cb]
> (0x0080): Going offline. Running callbacks.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [child_handler_setup]
> (0x2000): Setting up signal handler up for pid [8942]
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [child_handler_setup]
> (0x2000): Signal handler set up for pid [8942]
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [write_pipe_handler]
> (0x0400): All data has been sent!
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [child_sig_handler]
> (0x1000): Waiting for child [8942].
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [child_sig_handler]
> (0x0100): child [8942] finished successfully.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [read_pipe_handler]
> (0x0400): EOF received, client finished
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [parse_krb5_child_response]
> (0x1000): child response [0][3][44].
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [krb5_mod_ccname] (0x4000):
> Save ccname [FILE:/var/tmp/krb5cc_1000_IBmIM5] for user [ced...@eccm.lan].
> ....
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]]
> [check_failed_login_attempts] (0x4000): Failed login attempts [0], allowed
> failed login attempts [0], failed login delay [5].
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [sysdb_cache_auth]
> (0x0100): Cached credentials not available.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [ldb] (0x4000): cancel ldb
> transaction (nesting: 0)
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [krb5_auth_cache_creds]
> (0x0020): Offline authentication failed
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [check_wait_queue]
> (0x1000): Wait queue for user [ced...@eccm.lan] is empty.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [krb5_auth_queue_done]
> (0x1000): krb5_auth_queue request [0x560ea0455cc0] done.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_req_done] (0x0400): DP
> Request [PAM Authenticate #3]: Request handler finished [0]: Succès
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [_dp_req_recv] (0x0400): DP
> Request [PAM Authenticate #3]: Receiving request data.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_req_destructor]
> (0x0400): DP Request [PAM Authenticate #3]: Request removed.
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_req_destructor]
> (0x0400): Number of active DP request: 0
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_method_enabled]
> (0x0400): Target selinux is not configured
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [dp_pam_reply] (0x1000): DP
> Request [PAM Authenticate #3]: Sending result [6][ECCM.LAN]
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [remove_krb5_info_files]
> (0x0200): Could not remove [/var/lib/sss/pubconf/kdcinfo.ECCM.LAN],
> [2][Aucun fichier ou dossier de ce type]
> (Tue May 1 12:35:44 2018) [sssd[be[ECCM.LAN]]] [remove_krb5_info_files]
> (0x0200): Could not remove [/var/lib/sss/pubconf/kpasswdinfo.ECCM.LAN],
> [2][Aucun fichier ou dossier de ce type]
>
> I am a bit confused with credentials cache which as far as I understood are
> stored in /var/lib/sss/db/ but looking at the logfile, it seems that the
> target of offline authentification is to find the kerberos ticket into
> /var/tmp ( by the way those tickets are still present after reboot). If as
> I understood the passwd is cached as a Hash key in the sss/db files, we
> should be able to be authenticated even if we do not have the kerberos
> ticket anymore isn't it ?
>
> Actually, it seems that credentials cache cleaning erases the old_ccname if
> I look at the following log line :
>
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [unpack_buffer]
> (0x2000): No old ccache
> (Tue May 1 12:35:44 2018) [[sssd[krb5_child[8942]]]] [unpack_buffer]
> (0x0100): ccname: [FILE:/var/tmp/krb5cc_1000_XXXXXX] old_ccname: [not set]
> keytab: [/etc/krb5.keytab]
>
> When the Offline authentication succeed, I observe the following
> krb5_child.log :
>
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [main] (0x0400):
> krb5_child started.
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [unpack_buffer]
> (0x1000): total buffer size: [160]
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [unpack_buffer]
> (0x0100): cmd [241] uid [1000] gid [1000] validate [true] enterprise
> principal [false] offline [true] UPN [ced...@eccm.lan]
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [unpack_buffer]
> (0x0100): ccname: [FILE:/var/tmp/krb5cc_1000_XXXXXX] old_ccname:
> [FILE:/var/tmp/krb5cc_1000_vbmc1v] keytab: [/etc/krb5.keytab]
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [check_use_fast]
> (0x0100): Not using FAST.
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [switch_creds]
> (0x0200): Switch user to [1000][1000].
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [switch_creds]
> (0x0200): Switch user to [0][0].
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]]
> [k5c_check_old_ccache] (0x4000): Ccache_file is
> [FILE:/var/tmp/krb5cc_1000_vbmc1v] and is active and TGT is valid.
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]]
> [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [become_user]
> (0x0200): Trying to become user [1000][1000].
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [main] (0x2000):
> Running as [1000][1000].
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [become_user]
> (0x0200): Trying to become user [1000][1000].
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [become_user]
> (0x0200): Already user [1000].
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [k5c_setup]
> (0x2000): Running as [1000][1000].
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]]
> [set_lifetime_options] (0x0100): No specific renewable lifetime requested.
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]]
> [set_lifetime_options] (0x0100): No specific lifetime requested.
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [main] (0x0400):
> Will perform offline auth
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]]
> [create_empty_ccache] (0x1000): Existing ccache still valid, reusing
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [k5c_send_data]
> (0x0200): Received error code 0
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]]
> [pack_response_packet] (0x2000): response packet size: [56]
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [k5c_send_data]
> (0x4000): Response sent.
> (Tue May 1 13:17:16 2018) [[sssd[krb5_child[10318]]]] [main] (0x0400):
> krb5_child completed successfully
>
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [fo_resolve_service_send]
> (0x0020): No available servers for service 'KERBEROS'
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [be_resolve_server_done]
> (0x1000): Server resolution failed: [5]: Erreur d'entrée/sortie
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [be_mark_dom_offline]
> (0x1000): Marking back end offline
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [be_mark_offline] (0x2000):
> Going offline!
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [be_mark_offline] (0x2000):
> Enable check_if_online_ptask.
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [be_ptask_enable] (0x0400):
> Task [Check if online (periodic)]: enabling task
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [be_ptask_schedule]
> (0x0400): Task [Check if online (periodic)]: scheduling task 80 seconds
> from now [1525174023]
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [be_run_offline_cb]
> (0x0080): Going offline. Running callbacks.
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [child_handler_setup]
> (0x2000): Setting up signal handler up for pid [10471]
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [child_handler_setup]
> (0x2000): Signal handler set up for pid [10471]
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [write_pipe_handler]
> (0x0400): All data has been sent!
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [read_pipe_handler]
> (0x0400): EOF received, client finished
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [parse_krb5_child_response]
> (0x1000): child response [0][3][44].
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [krb5_mod_ccname] (0x4000):
> Save ccname [FILE:/var/tmp/krb5cc_1000_vbmc1v] for user [ced...@eccm.lan].
> ....
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [sysdb_set_entry_attr]
> (0x0200): Entry [name=ced...@eccm.lan,cn=users,cn=ECCM.LAN,cn=sysdb] has
> set [ts_cache] attrs.
>
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]]
> [check_failed_login_attempts] (0x4000): Failed login attempts [0], allowed
> failed login attempts [0], failed login delay [5].
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [sysdb_cache_auth]
> (0x0100): Hashes do match!
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [ldb] (0x4000): commit ldb
> transaction (nesting: 0)
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]]
> [add_user_to_delayed_online_authentication] (0x4000): Saved authtok of user
> [ced...@eccm.lan] with serial [184462369].
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]]
> [add_user_to_delayed_online_authentication] (0x4000): Added user
> [ced...@eccm.lan] successfully to delayed online authentication.
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [check_wait_queue]
> (0x1000): Wait queue for user [ced...@eccm.lan] is empty.
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [krb5_auth_queue_done]
> (0x1000): krb5_auth_queue request [0x55ffb8dee140] done.
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [authenticate_user_done]
> (0x0020): Failed to authenticate user [ced...@eccm.lan].
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [child_sig_handler]
> (0x1000): Waiting for child [10471].
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [child_sig_handler]
> (0x0100): child [10471] finished successfully.
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [remove_krb5_info_files]
> (0x0200): Could not remove [/var/lib/sss/pubconf/kdcinfo.ECCM.LAN],
> [2][Aucun fichier ou dossier de ce type]
> (Tue May 1 13:25:43 2018) [sssd[be[ECCM.LAN]]] [remove_krb5_info_files]
> (0x0200): Could not remove [/var/lib/sss/pubconf/kpasswdinfo.ECCM.LAN],
> [2][Aucun fichier ou dossier de ce type]
>
> Thanks a lot for your help.
> Regards
> Cedric
> _______________________________________________
> sssd-users mailing list -- sssd-users@lists.fedorahosted.org
> To unsubscribe send an email to sssd-users-le...@lists.fedorahosted.org
_______________________________________________
sssd-users mailing list -- sssd-users@lists.fedorahosted.org
To unsubscribe send an email to sssd-users-le...@lists.fedorahosted.org
