On (19/05/17 12:07), Joakim Tjernlund wrote: >On Fri, 2017-05-19 at 13:43 +0200, Lukas Slebodnik wrote: >> On (19/05/17 11:31), Joakim Tjernlund wrote: >> > On Fri, 2017-05-19 at 13:22 +0200, Lukas Slebodnik wrote: >> > > On (19/05/17 10:37), Joakim Tjernlund wrote: >> > > > On Thu, 2017-05-18 at 11:40 -0400, Striker Leggette wrote: >> > > > > I can understand the first unlock from waking up from sleep. For >> > > > > the second, bump your debug_level in sssd.conf up to 7 and then >> > > > > check to see if you have any "Got request" lines in >> > > > > /var/log/sssd/sssd_domain.log for the second login attempt from the >> > > > > lock screen. You should be able to see if it is using cached creds >> > > > > or actively trying to parse the domain server. >> > > > > Can you paste your sssd.conf also? >> > > > >> > > > I not using a VPN, local ethernet (got wifi too bu in this case eth is >> > > > connected) >> > > > >> > > >> > > And log file says there are problem with resolution of DNS names. >> > > >> > > e.g. >> > > [fo_resolve_service_done] (0x0020): Failed to resolve server >> > > 'se-dc01.infinera.com': Could not contact DNS servers >> > > [fo_resolve_service_done] (0x0020): Failed to resolve server >> > > 'se-dc02.infinera.com': Could not contact DNS servers >> > > [fo_resolve_service_done] (0x0020): Failed to resolve server >> > > 'sv-dc01.infinera.com': Could not contact DNS servers >> > > [fo_resolve_service_done] (0x0020): Failed to resolve server >> > > 'sv-dc02.infinera.com': Could not contact DNS servers >> > > >> > > Therefore sssd works in offline mode and therefore cannot renew a ticket. >> > >> > ping and nslookup work fine, I just did a new lock unlock and this is the >> > log from this that action. >> > I still did not get a new ticket. >> > >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_server_status] >> > (0x1000): Status of server 'se-dc01.infinera.com' is 'working' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x1000): Port status of port 0 for server 'se-dc01.infinera.com' is 'not >> > working' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x0080): SSSD is unable to complete the full connection request, this >> > internal status does not necessarily indicate network port issues. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_server_status] >> > (0x1000): Status of server 'se-dc02.infinera.com' is 'name resolved' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x1000): Port status of port 0 for server 'se-dc02.infinera.com' is 'not >> > working' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x0080): SSSD is unable to complete the full connection request, this >> > internal status does not necessarily indicate network port issues. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_server_status] >> > (0x1000): Status of server 'sv-dc01.infinera.com' is 'name resolved' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x1000): Port status of port 0 for server 'sv-dc01.infinera.com' is 'not >> > working' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x0080): SSSD is unable to complete the full connection request, this >> > internal status does not necessarily indicate network port issues. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_server_status] >> > (0x1000): Status of server 'sv-dc02.infinera.com' is 'name not resolved' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x1000): Port status of port 0 for server 'sv-dc02.infinera.com' is >> > 'neutral' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_server_status] >> > (0x1000): Status of server 'sv-dc02.infinera.com' is 'name not resolved' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of >> > 'sv-dc02.infinera.com' in files >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [set_server_common_status] (0x0100): Marking server 'sv-dc02.infinera.com' >> > as 'resolving name' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record >> > of 'sv-dc02.infinera.com' in files >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [resolv_gethostbyname_next] (0x0200): No more address families to retry >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of >> > 'sv-dc02.infinera.com' in DNS >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [request_watch_destructor] (0x0400): Deleting request watch >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [set_server_common_status] (0x0100): Marking server 'sv-dc02.infinera.com' >> > as 'name resolved' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [be_resolve_server_process] (0x0200): Found address for server >> > sv-dc02.infinera.com: [10.100.98.22] TTL 3600 >> >> looks like name was properly resolved here >> >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [ad_resolve_callback] >> > (0x0100): Constructed uri 'ldap://sv-dc02.infinera.com' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [ad_resolve_callback] >> > (0x0100): Constructed GC uri 'ldap://sv-dc02.infinera.com' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [be_primary_server_timeout_activate] (0x0400): The primary server >> > reconnection is already scheduled >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [sss_domain_get_state] >> > (0x1000): Domain infinera.com is Active >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [write_pipe_handler] >> > (0x0400): All data has been sent! >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [delayed_online_authentication_callback] (0x0200): Backend is online, >> > starting delayed online authentication. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [authenticate_stored_users] (0x0020): User [[email protected]] is still >> > logged in, trying online authentication. >> >> SSSD tried to authenticate online here. >> >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [child_sig_handler] >> > (0x1000): Waiting for child [15431]. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [child_sig_handler] >> > (0x0100): child [15431] finished successfully. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [krb5_auth_queue_send] >> > (0x1000): Request [0xefd900] successfully added to wait queue of user >> > [[email protected]]. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [read_pipe_handler] >> > (0x0400): EOF received, client finished >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [fo_set_port_status] >> > (0x0100): Marking port 0 of server 'sv-dc02.infinera.com' as 'not working' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [fo_set_port_status] >> > (0x0400): Marking port 0 of duplicate server 'sv-dc02.infinera.com' as >> > 'not working' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_server_status] >> > (0x1000): Status of server 'se-dc01.infinera.com' is 'working' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x1000): Port status of port 0 for server 'se-dc01.infinera.com' is 'not >> > working' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x0080): SSSD is unable to complete the full connection request, this >> > internal status does not necessarily indicate network port issues. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_server_status] >> > (0x1000): Status of server 'se-dc02.infinera.com' is 'name resolved' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x1000): Port status of port 0 for server 'se-dc02.infinera.com' is 'not >> > working' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x0080): SSSD is unable to complete the full connection request, this >> > internal status does not necessarily indicate network port issues. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_server_status] >> > (0x1000): Status of server 'sv-dc01.infinera.com' is 'name resolved' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x1000): Port status of port 0 for server 'sv-dc01.infinera.com' is 'not >> > working' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x0080): SSSD is unable to complete the full connection request, this >> > internal status does not necessarily indicate network port issues. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_server_status] >> > (0x1000): Status of server 'sv-dc02.infinera.com' is 'name resolved' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x1000): Port status of port 0 for server 'sv-dc02.infinera.com' is 'not >> > working' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [get_port_status] >> > (0x0080): SSSD is unable to complete the full connection request, this >> > internal status does not necessarily indicate network port issues. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [fo_resolve_service_send] (0x0020): No available servers for service 'AD' >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [be_resolve_server_done] (0x1000): Server resolution failed: [5]: >> > Input/output error >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [be_mark_dom_offline] >> > (0x1000): Marking back end offline >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [be_ptask_enable] >> > (0x0400): Task [Check if online (periodic)]: enabling task >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [be_ptask_schedule] >> > (0x0400): Task [Check if online (periodic)]: scheduling task 81 seconds >> > from now [1495193169] >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [be_run_offline_cb] >> > (0x0080): Going offline. Running callbacks. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [write_pipe_handler] >> > (0x0400): All data has been sent! >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [read_pipe_handler] >> > (0x0400): EOF received, client finished >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] >> > [parse_krb5_child_response] (0x0020): message too short. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [krb5_auth_done] >> > (0x0040): Could not parse child response [22]: Invalid argument >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [krb5_auth_queue_done] >> > (0x0040): krb5_auth_recv failed with: 22 >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [renew_tgt_done] >> > (0x0020): krb5_auth request failed. >> > (Fri May 19 13:24:48 2017) [sssd[be[infinera.com]]] [renew_tgt_done] >> > (0x0200): Giving back pam data. >> >> But renew failed and sssd went offline. >> >> Could you truncate sssd log file (truncate -s 0 /var/log/sssd/*) >> Then try to reproduce one more time and provide not only domain log file but >> also *child log files. > >Did that but I did not get a child log file at all. >
If you can see debug messages from following functions write_pipe_handler read_pipe_handler parse_krb5_child_response Then krb5_child was executed. And there will be non-empty file /var/log/sssd/krb5_child.log. >> Attachments or pastebin are usually better >> then direct inclusion of log into mail. > >Sure, will attach next time Looking forward to new log files :-) LS _______________________________________________ sssd-users mailing list -- [email protected] To unsubscribe send an email to [email protected]
