1

By following this documentation, I succesfully joined my Ubuntu 16.04 LTS servers to my Active Directory running a pair of Windows 2016 domain controllers. It has been working for about two weeks but is somehow no longer working. I enabled debugging on sssd to get a fair amount of logging but I can't seem to pinpoint the issue.

To be more precise, I am still able to get user and group information (using getent passwd or getent group) from the system but the authentication is not working from SSH and using sudo.

I have attached a fair amount of debugging data in case anyone could help me on figuring out what's wrong.

/var/log/sssd/sssd.log

(Wed Aug 23 14:40:03:010480 2017) [sssd] [service_send_ping] (0x2000): Pinging MY.DOMAIN (Wed Aug 23 14:40:03:010710 2017) [sssd] [sbus_add_timeout] (0x2000): 0x195eec0 (Wed Aug 23 14:40:03:010800 2017) [sssd] [service_send_ping] (0x2000): Pinging nss (Wed Aug 23 14:40:03:010872 2017) [sssd] [sbus_add_timeout] (0x2000): 0x195ccb0 (Wed Aug 23 14:40:03:011026 2017) [sssd] [service_send_ping] (0x2000): Pinging pam (Wed Aug 23 14:40:03:011097 2017) [sssd] [sbus_add_timeout] (0x2000): 0x195f0f0 (Wed Aug 23 14:40:03:011250 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x195ccb0 (Wed Aug 23 14:40:03:011326 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1959bf0 (Wed Aug 23 14:40:03:011373 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Aug 23 14:40:03:011444 2017) [sssd] [ping_check] (0x2000): Service nss replied to ping (Wed Aug 23 14:40:03:011503 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x195f0f0 (Wed Aug 23 14:40:03:011555 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x195baa0 (Wed Aug 23 14:40:03:011601 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Aug 23 14:40:03:011659 2017) [sssd] [ping_check] (0x2000): Service pam replied to ping (Wed Aug 23 14:40:03:012041 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x195eec0 (Wed Aug 23 14:40:03:012104 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x19540f0 (Wed Aug 23 14:40:03:012151 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Aug 23 14:40:03:012195 2017) [sssd] [ping_check] (0x2000): Service MY.DOMAIN replied to ping

/var/log/sssd/sssd_MY.DOMAIN.log

(Wed Aug 23 14:40:03:011748 2017) [sssd[be[MY.DOMAIN]]] [sbus_dispatch] (0x4000): dbus conn: 0x192cd10 (Wed Aug 23 14:40:03:011842 2017) [sssd[be[MY.DOMAIN]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Aug 23 14:40:03:011898 2017) [sssd[be[MY.DOMAIN]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Wed Aug 23 14:40:03:011953 2017) [sssd[be[MY.DOMAIN]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Aug 23 14:40:05:413488 2017) [sssd[be[MY.DOMAIN]]] [sbus_dispatch] (0x4000): dbus conn: 0x1966440 (Wed Aug 23 14:40:05:413583 2017) [sssd[be[MY.DOMAIN]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Aug 23 14:40:05:413644 2017) [sssd[be[MY.DOMAIN]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Wed Aug 23 14:40:05:413700 2017) [sssd[be[MY.DOMAIN]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Aug 23 14:40:05:413747 2017) [sssd[be[MY.DOMAIN]]] [be_get_account_info] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][1][name=myuser] (Wed Aug 23 14:40:05:413825 2017) [sssd[be[MY.DOMAIN]]] [be_req_set_domain] (0x0400): Changing request domain from [MY.DOMAIN] to [MY.DOMAIN] (Wed Aug 23 14:40:05:413923 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1971ea0 (Wed Aug 23 14:40:05:413979 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x192d4b0 (Wed Aug 23 14:40:05:414043 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x1971ea0 "ltdb_callback" (Wed Aug 23 14:40:05:414196 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x192d4b0 "ltdb_timeout" (Wed Aug 23 14:40:05:414261 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x1971ea0 "ltdb_callback" (Wed Aug 23 14:40:05:414324 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1931b70 (Wed Aug 23 14:40:05:414380 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1975fc0 (Wed Aug 23 14:40:05:414429 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x1931b70 "ltdb_callback" (Wed Aug 23 14:40:05:414522 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x192f6f0 (Wed Aug 23 14:40:05:414577 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x192f7b0 (Wed Aug 23 14:40:05:414622 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x1975fc0 "ltdb_timeout" (Wed Aug 23 14:40:05:414676 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x1931b70 "ltdb_callback" (Wed Aug 23 14:40:05:414721 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x192f6f0 "ltdb_callback" (Wed Aug 23 14:40:05:414790 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1975fc0 (Wed Aug 23 14:40:05:414856 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1933580 (Wed Aug 23 14:40:05:414898 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x192f7b0 "ltdb_timeout" (Wed Aug 23 14:40:05:414942 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x192f6f0 "ltdb_callback" (Wed Aug 23 14:40:05:414990 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x1975fc0 "ltdb_callback" (Wed Aug 23 14:40:05:415075 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1974850 (Wed Aug 23 14:40:05:415134 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1933640 (Wed Aug 23 14:40:05:415182 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x1933580 "ltdb_timeout" (Wed Aug 23 14:40:05:415226 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x1975fc0 "ltdb_callback" (Wed Aug 23 14:40:05:415281 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x1974850 "ltdb_callback" (Wed Aug 23 14:40:05:415350 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1933580 (Wed Aug 23 14:40:05:415409 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1973ee0 (Wed Aug 23 14:40:05:415455 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x1933640 "ltdb_timeout" (Wed Aug 23 14:40:05:415506 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x1974850 "ltdb_callback" (Wed Aug 23 14:40:05:415553 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x1933580 "ltdb_callback" (Wed Aug 23 14:40:05:415637 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x19735d0 (Wed Aug 23 14:40:05:415691 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1974850 (Wed Aug 23 14:40:05:415735 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x1973ee0 "ltdb_timeout" (Wed Aug 23 14:40:05:415788 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x1933580 "ltdb_callback" (Wed Aug 23 14:40:05:415833 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x19735d0 "ltdb_callback" (Wed Aug 23 14:40:05:415921 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1973ee0 (Wed Aug 23 14:40:05:415961 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x19774b0 (Wed Aug 23 14:40:05:416023 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x1974850 "ltdb_timeout" (Wed Aug 23 14:40:05:416068 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x19735d0 "ltdb_callback" (Wed Aug 23 14:40:05:416113 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x1973ee0 "ltdb_callback" (Wed Aug 23 14:40:05:416192 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1934d00 (Wed Aug 23 14:40:05:416244 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x19735d0 (Wed Aug 23 14:40:05:416297 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x19774b0 "ltdb_timeout" (Wed Aug 23 14:40:05:416342 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x1973ee0 "ltdb_callback" (Wed Aug 23 14:40:05:416386 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x1934d00 "ltdb_callback" (Wed Aug 23 14:40:05:416462 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x19774b0 (Wed Aug 23 14:40:05:416513 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1974850 (Wed Aug 23 14:40:05:416567 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x19735d0 "ltdb_timeout" (Wed Aug 23 14:40:05:416613 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x1934d00 "ltdb_callback" (Wed Aug 23 14:40:05:416671 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x19774b0 "ltdb_callback" (Wed Aug 23 14:40:05:416753 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x19349d0 (Wed Aug 23 14:40:05:416815 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1971c90 (Wed Aug 23 14:40:05:416861 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x1974850 "ltdb_timeout" (Wed Aug 23 14:40:05:416925 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x19774b0 "ltdb_callback" (Wed Aug 23 14:40:05:416965 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x19349d0 "ltdb_callback" (Wed Aug 23 14:40:05:417015 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x1971c90 "ltdb_timeout" (Wed Aug 23 14:40:05:417076 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x19349d0 "ltdb_callback" (Wed Aug 23 14:40:05:417188 2017) [sssd[be[MY.DOMAIN]]] [sbus_add_timeout] (0x2000): 0x197af90 (Wed Aug 23 14:40:05:417664 2017) [sssd[be[MY.DOMAIN]]] [sbus_remove_timeout] (0x2000): 0x197af90 (Wed Aug 23 14:40:05:417756 2017) [sssd[be[MY.DOMAIN]]] [sbus_dispatch] (0x4000): dbus conn: 0x1962fe0 (Wed Aug 23 14:40:05:417810 2017) [sssd[be[MY.DOMAIN]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Aug 23 14:40:05:418094 2017) [sssd[be[MY.DOMAIN]]] [acctinfo_callback] (0x0100): Request processed. Returned 1,11,Offline (Wed Aug 23 14:40:05:418200 2017) [sssd[be[MY.DOMAIN]]] [sbus_dispatch] (0x4000): dbus conn: 0x1966440 (Wed Aug 23 14:40:05:418258 2017) [sssd[be[MY.DOMAIN]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Aug 23 14:40:05:418316 2017) [sssd[be[MY.DOMAIN]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.pamHandler on path /org/freedesktop/sssd/dataprovider (Wed Aug 23 14:40:05:418366 2017) [sssd[be[MY.DOMAIN]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Aug 23 14:40:05:418426 2017) [sssd[be[MY.DOMAIN]]] [be_req_set_domain] (0x0400): Changing request domain from [MY.DOMAIN] to [MY.DOMAIN] (Wed Aug 23 14:40:05:418476 2017) [sssd[be[MY.DOMAIN]]] [be_pam_handler] (0x0100): Got request with the following data (Wed Aug 23 14:40:05:418532 2017) [sssd[be[MY.DOMAIN]]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Wed Aug 23 14:40:05:418583 2017) [sssd[be[MY.DOMAIN]]] [pam_print_data] (0x0100): domain: MY.DOMAIN (Wed Aug 23 14:40:05:418635 2017) [sssd[be[MY.DOMAIN]]] [pam_print_data] (0x0100): user: myuser (Wed Aug 23 14:40:05:418679 2017) [sssd[be[MY.DOMAIN]]] [pam_print_data] (0x0100): service: sshd (Wed Aug 23 14:40:05:418721 2017) [sssd[be[MY.DOMAIN]]] [pam_print_data] (0x0100): tty: ssh (Wed Aug 23 14:40:05:418773 2017) [sssd[be[MY.DOMAIN]]] [pam_print_data] (0x0100): ruser: (Wed Aug 23 14:40:05:418815 2017) [sssd[be[MY.DOMAIN]]] [pam_print_data] (0x0100): rhost: 10.10.10.10 (Wed Aug 23 14:40:05:418863 2017) [sssd[be[MY.DOMAIN]]] [pam_print_data] (0x0100): authtok type: 1 (Wed Aug 23 14:40:05:418908 2017) [sssd[be[MY.DOMAIN]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Aug 23 14:40:05:418951 2017) [sssd[be[MY.DOMAIN]]] [pam_print_data] (0x0100): priv: 1 (Wed Aug 23 14:40:05:419000 2017) [sssd[be[MY.DOMAIN]]] [pam_print_data] (0x0100): cli_pid: 1647 (Wed Aug 23 14:40:05:419043 2017) [sssd[be[MY.DOMAIN]]] [pam_print_data] (0x0100): logon name: not set (Wed Aug 23 14:40:05:419100 2017) [sssd[be[MY.DOMAIN]]] [krb5_auth_queue_send] (0x1000): Wait queue of user [myuser] is empty, running request [0x1976110] immediately. (Wed Aug 23 14:40:05:419162 2017) [sssd[be[MY.DOMAIN]]] [krb5_setup] (0x4000): No mapping for: myuser (Wed Aug 23 14:40:05:419242 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1931b70 (Wed Aug 23 14:40:05:419294 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1974850 (Wed Aug 23 14:40:05:419340 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x1931b70 "ltdb_callback" (Wed Aug 23 14:40:05:419453 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x1974850 "ltdb_timeout" (Wed Aug 23 14:40:05:419510 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x1931b70 "ltdb_callback" (Wed Aug 23 14:40:05:419571 2017) [sssd[be[MY.DOMAIN]]] [krb5_auth_send] (0x0100): Home directory for user [myuser] not known. (Wed Aug 23 14:40:05:419636 2017) [sssd[be[MY.DOMAIN]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Wed Aug 23 14:40:05:419694 2017) [sssd[be[MY.DOMAIN]]] [get_server_status] (0x1000): Status of server 'adsrv2.my.domain' is 'working' (Wed Aug 23 14:40:05:419741 2017) [sssd[be[MY.DOMAIN]]] [get_port_status] (0x1000): Port status of port 389 for server 'adsrv2.my.domain' is 'working' (Wed Aug 23 14:40:05:419781 2017) [sssd[be[MY.DOMAIN]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Wed Aug 23 14:40:05:419825 2017) [sssd[be[MY.DOMAIN]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Aug 23 14:40:05:419884 2017) [sssd[be[MY.DOMAIN]]] [get_server_status] (0x1000): Status of server 'adsrv2.my.domain' is 'working' (Wed Aug 23 14:40:05:419938 2017) [sssd[be[MY.DOMAIN]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Aug 23 14:40:05:419985 2017) [sssd[be[MY.DOMAIN]]] [be_resolve_server_process] (0x0200): Found address for server adsrv2.my.domain: [10.20.20.20] TTL 1200 (Wed Aug 23 14:40:05:420038 2017) [sssd[be[MY.DOMAIN]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://adsrv2.my.domain' (Wed Aug 23 14:40:05:420077 2017) [sssd[be[MY.DOMAIN]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://adsrv2.my.domain' (Wed Aug 23 14:40:05:420294 2017) [sssd[be[MY.DOMAIN]]] [unique_filename_destructor] (0x2000): Unlinking [/var/lib/sss/pubconf/.krb5info_dummy_7y62r4] (Wed Aug 23 14:40:05:420368 2017) [sssd[be[MY.DOMAIN]]] [unlink_dbg] (0x2000): File already removed: [/var/lib/sss/pubconf/.krb5info_dummy_7y62r4] (Wed Aug 23 14:40:05:421405 2017) [sssd[be[MY.DOMAIN]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [1648] (Wed Aug 23 14:40:05:421732 2017) [sssd[be[MY.DOMAIN]]] [child_handler_setup] (0x2000): Signal handler set up for pid [1648] (Wed Aug 23 14:40:05:421813 2017) [sssd[be[MY.DOMAIN]]] [write_pipe_handler] (0x0400): All data has been sent! (Wed Aug 23 14:40:05:428549 2017) [sssd[be[MY.DOMAIN]]] [read_pipe_handler] (0x0400): EOF received, client finished (Wed Aug 23 14:40:05:428634 2017) [sssd[be[MY.DOMAIN]]] [parse_krb5_child_response] (0x1000): child response [0][3][46]. (Wed Aug 23 14:40:05:428690 2017) [sssd[be[MY.DOMAIN]]] [_be_fo_set_port_status] (0x8000): Setting status: PORT_WORKING. Called from: ../src/providers/krb5/krb5_auth.c: krb5_auth_done: 1039 (Wed Aug 23 14:40:05:428742 2017) [sssd[be[MY.DOMAIN]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'adsrv2.my.domain' as 'working' (Wed Aug 23 14:40:05:428777 2017) [sssd[be[MY.DOMAIN]]] [set_server_common_status] (0x0100): Marking server 'adsrv2.my.domain' as 'working' (Wed Aug 23 14:40:05:428828 2017) [sssd[be[MY.DOMAIN]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'adsrv2.my.domain' as 'working' (Wed Aug 23 14:40:05:428870 2017) [sssd[be[MY.DOMAIN]]] [krb5_mod_ccname] (0x4000): Save ccname [FILE:/tmp/krb5cc_1763801121_5SWlrn] for user [myuser]. (Wed Aug 23 14:40:05:428920 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): start ldb transaction (nesting: 0) (Wed Aug 23 14:40:05:429053 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): start ldb transaction (nesting: 1) (Wed Aug 23 14:40:05:429130 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x196d020 (Wed Aug 23 14:40:05:429184 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1932290 (Wed Aug 23 14:40:05:429237 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Running timer event 0x196d020 "ltdb_callback" (Wed Aug 23 14:40:05:429355 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Destroying timer event 0x1932290 "ltdb_timeout" (Wed Aug 23 14:40:05:429424 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): Ending timer event 0x196d020 "ltdb_callback" (Wed Aug 23 14:40:05:429470 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): commit ldb transaction (nesting: 1) (Wed Aug 23 14:40:05:431594 2017) [sssd[be[MY.DOMAIN]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) (Wed Aug 23 14:40:05:433074 2017) [sssd[be[MY.DOMAIN]]] [krb5_auth_done] (0x0100): Backend is marked offline, retry later! (Wed Aug 23 14:40:05:433148 2017) [sssd[be[MY.DOMAIN]]] [check_wait_queue] (0x1000): Wait queue for user [myuser] is empty. (Wed Aug 23 14:40:05:433199 2017) [sssd[be[MY.DOMAIN]]] [krb5_auth_queue_done] (0x1000): krb5_auth_queue request [0x1976110] done. (Wed Aug 23 14:40:05:433246 2017) [sssd[be[MY.DOMAIN]]] [be_pam_handler_callback] (0x0100): Backend returned: (1, 9, <NULL>) [Provider is Offline] (Wed Aug 23 14:40:05:433291 2017) [sssd[be[MY.DOMAIN]]] [be_pam_handler_callback] (0x0100): Sending result [9][MY.DOMAIN] (Wed Aug 23 14:40:05:433861 2017) [sssd[be[MY.DOMAIN]]] [be_pam_handler_callback] (0x0100): Sent result [9][MY.DOMAIN] (Wed Aug 23 14:40:05:433932 2017) [sssd[be[MY.DOMAIN]]] [child_sig_handler] (0x1000): Waiting for child [1648]. (Wed Aug 23 14:40:05:433991 2017) [sssd[be[MY.DOMAIN]]] [child_sig_handler] (0x0100): child [1648] finished successfully.

/var/log/auth.log

Aug 23 14:40:05 myhostname sshd[1647]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=10.10.10.10 user=myuser Aug 23 14:40:06 myhostname sshd[1645]: error: PAM: Authentication failure for myuser from 10.10.10.10 Aug 23 14:40:08 myhostname sshd[1645]: error: Received disconnect from 10.10.10.10 port 54226:13: Unable to authenticate [preauth] Aug 23 14:40:08 myhostname sshd[1645]: Disconnected from 10.10.10.10 port 54226 [preauth] Aug 23 14:40:05 myhostname sshd[1647]: pam_sss(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=10.10.10.10 user=myuser Aug 23 14:40:05 myhostname sshd[1647]: pam_sss(sshd:auth): received for user myuser: 9 (Authentication service cannot retrieve authentication info)

/var/log/sssd/krb5_child.log

(Wed Aug 23 14:40:05:423929 2017) [[sssd[krb5_child[1648]]]] [main] (0x0400): krb5_child started. (Wed Aug 23 14:40:05:424052 2017) [[sssd[krb5_child[1648]]]] [unpack_buffer] (0x1000): total buffer size: [167] (Wed Aug 23 14:40:05:424115 2017) [[sssd[krb5_child[1648]]]] [unpack_buffer] (0x0100): cmd [241] uid [1763801121] gid [1763800513] validate [true] enterprise principal [false] offline [true] UPN [[email protected]] (Wed Aug 23 14:40:05:424179 2017) [[sssd[krb5_child[1648]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_1763801121_XXXXXX] old_ccname: [FILE:/tmp/krb5cc_1763801121_5SWlrn] keytab: [/etc/krb5.keytab] (Wed Aug 23 14:40:05:424454 2017) [[sssd[krb5_child[1648]]]] [check_use_fast] (0x0100): Not using FAST. (Wed Aug 23 14:40:05:424519 2017) [[sssd[krb5_child[1648]]]] [switch_creds] (0x0200): Switch user to [1763801121][1763800513]. (Wed Aug 23 14:40:05:424689 2017) [[sssd[krb5_child[1648]]]] [switch_creds] (0x0200): Switch user to [0][0]. (Wed Aug 23 14:40:05:427555 2017) [[sssd[krb5_child[1648]]]] [k5c_check_old_ccache] (0x4000): Ccache_file is [FILE:/tmp/krb5cc_1763801121_5SWlrn] and is not active and TGT is valid. (Wed Aug 23 14:40:05:427655 2017) [[sssd[krb5_child[1648]]]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (Wed Aug 23 14:40:05:427709 2017) [[sssd[krb5_child[1648]]]] [become_user] (0x0200): Trying to become user [1763801121][1763800513]. (Wed Aug 23 14:40:05:427759 2017) [[sssd[krb5_child[1648]]]] [main] (0x2000): Running as [1763801121][1763800513]. (Wed Aug 23 14:40:05:427810 2017) [[sssd[krb5_child[1648]]]] [become_user] (0x0200): Trying to become user [1763801121][1763800513]. (Wed Aug 23 14:40:05:427864 2017) [[sssd[krb5_child[1648]]]] [become_user] (0x0200): Already user [1763801121]. (Wed Aug 23 14:40:05:427909 2017) [[sssd[krb5_child[1648]]]] [k5c_setup] (0x2000): Running as [1763801121][1763800513]. (Wed Aug 23 14:40:05:427961 2017) [[sssd[krb5_child[1648]]]] [set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment. (Wed Aug 23 14:40:05:428012 2017) [[sssd[krb5_child[1648]]]] [set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment. (Wed Aug 23 14:40:05:428060 2017) [[sssd[krb5_child[1648]]]] [main] (0x0400): Will perform offline auth (Wed Aug 23 14:40:05:428109 2017) [[sssd[krb5_child[1648]]]] [create_empty_ccache] (0x1000): Existing ccache still valid, reusing (Wed Aug 23 14:40:05:428159 2017) [[sssd[krb5_child[1648]]]] [k5c_send_data] (0x0200): Received error code 0 (Wed Aug 23 14:40:05:428205 2017) [[sssd[krb5_child[1648]]]] [pack_response_packet] (0x2000): response packet size: [58] (Wed Aug 23 14:40:05:428271 2017) [[sssd[krb5_child[1648]]]] [k5c_send_data] (0x4000): Response sent. (Wed Aug 23 14:40:05:428325 2017) [[sssd[krb5_child[1648]]]] [main] (0x0400): krb5_child completed successfully

2 Answers 2

1

Okay, this took a while, but there was an issue with the ubuntu package for a while, it's been fixed sometime around november 2017

https://bugs.launchpad.net/ubuntu/+source/sssd/+bug/1684295

A simple package update fixed the whole thing, no modification had to happen anywhere.

0

Exactly as the logs say the machine is operating offline. Find the first occurence of "NOT_WORKING" or "Going offline" in the logs and it would tell you why..

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .