I actually have a followup to this already and it seems that I'm seeing segfaults and service restarts around the times of these failed attempts.

Here is a better bad login attempt sssd_domain.com.log log, at level 0x1310: ``` (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=jsmith(a)mydomain.com] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sshPublicKeys] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userCertificate;binary] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [mail] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=John Smith,CN=Users,DC=mydomain,DC=com]. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_add_references] (0x1000): Additional References: ldap://mydomain.com/CN=Configuration,DC=mydomain,DC=com (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sysdb_set_entry_attr] (0x0200): Entry [name=jsmith(a)mydomain.com,cn=users,cn=mydomain.com,cn=sysdb] has set [ts_cache] attrs. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [tokenGroups] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=John Smith,CN=Users,DC=mydomain,DC=com]. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID [S-1-5-32-545] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID [S-1-5-32-544] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID [S-1-5-21-1138762004-3630643508-13603300-572] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID [S-1-5-21-1138762004-3630643508-13603300-513] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID [S-1-5-21-1138762004-3630643508-13603300-1103] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_ad_tokengroups_get_posix_members] (0x1000): Processing membership SID [S-1-5-21-1138762004-3630643508-13603300-512] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_ad_tokengroups_update_members] (0x1000): Updating memberships for [ jsmith(a)mydomain.com] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sysdb_set_entry_attr] (0x0200): Entry [name=jsmith(a)mydomain.com,cn=users,cn=mydomain.com,cn=sysdb] has set [ts_cache] attrs. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_req_reply_std] (0x1000): DP Request [Initgroups #23]: Returning [Success]: 0,0,Success (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_pam_handler] (0x0100): Got request with the following data (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): domain: mydomain.com (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): user: jsmith(a)mydomain.com (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): service: sshd (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): tty: ssh (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): ruser: (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): rhost: 192.168.2.111 (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): authtok type: 0 (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): priv: 1 (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): cli_pid: 22339 (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): logon name: not set (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [distinguishedName] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=cerberusvm,CN=Computers,DC=mydomain,DC=com]. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_add_references] (0x1000): Additional References: ldap://mydomain.com/CN=Configuration,DC=mydomain,DC=com (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [DC=mydomain,DC=com]. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [netlogon] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [configurationNamingContext] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gPLink] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gpOptions] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [DC=mydomain,DC=com]. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gPLink] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gpOptions] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [cn=Default-First-Site-Name,cn=Sites,CN=Configuration,DC=mydomain,DC=com]. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): Entry has no attributes [0(Success)]!? (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nTSecurityDescriptor] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gPCFileSysPath] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gPCMachineExtensionNames] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gPCFunctionalityVersion] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [flags] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=mydomain,DC=com]. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [be_res_get_opts] (0x0100): Lookup order: ipv4_first (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [recreate_ares_channel] (0x0100): Initializing new c-ares channel (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [confdb_get_domain_internal] (0x1000): pwd_expiration_warning is -1 (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sysdb_domain_init_internal] (0x0200): DB File for mydomain.com: /var/lib/sss/db/cache_mydomain.com.ldb (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sysdb_domain_init_internal] (0x0200): Timestamp file for mydomain.com: /var/lib/sss/db/timestamps_mydomain.com.ldb (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [monitor_common_send_id] (0x0100): Sending ID: (%BE_mydomain.com,1) (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_names_init_from_args] (0x0100): Using re [(((?P&lt;domain&gt;[^\\]+)\\(?P&lt;name&gt;.+$))|((?P&lt;name&gt;[^@]+)@(?P&lt;domain&gt;.+$))|(^(?P&lt;name&gt;[^(a)\\]+)$))]. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [sss_fqnames_init] (0x0100): Using fq format [%1$s@%2$s]. (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [create_socket_symlink] (0x1000): Symlinking the dbus path /var/lib/sss/pipes/private/sbus-dp_mydomain.com.22340 to a link /var/lib/sss/pipes/private/sbus-dp_mydomain.com (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_load_configuration] (0x0100): Using [ad] provider for [id] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_load_configuration] (0x0100): Using [ad] provider for [auth] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_load_configuration] (0x0100): Using [ad] provider for [access] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_load_configuration] (0x0100): Using [ad] provider for [chpass] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_load_configuration] (0x0100): Using [ad] provider for [sudo] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_load_configuration] (0x0100): Using [ad] provider for [autofs] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_load_configuration] (0x0100): Using [ad] provider for [selinux] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_load_configuration] (0x0100): Using [ad] provider for [hostid] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_load_configuration] (0x0100): Using [ad] provider for [subdomains] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_load_configuration] (0x0100): Using [ad] provider for [session] (Wed Jan 16 16:07:35 2019) [sssd[be[mydomain.com]]] [dp_module_open_lib] (0x1000): Loading module [ad] with path [/usr/lib64/sssd/libsss_ad.so] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [ad_get_common_options] (0x0100): Setting domain option case_sensitive to [false] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [krb5_service_new] (0x0100): write_kdcinfo for realm mydomain.COM set to false (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [_ad_servers_init] (0x0100): Added failover server prodad1.mydomain.com (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [ad_set_sdap_options] (0x0100): Option krb5_realm set to mydomain.COM (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_set_sasl_options] (0x0100): Will look for cerberusvm.mydomain.com(a)mydomain.COM in default keytab (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [select_principal_from_keytab] (0x0200): trying to select the most appropriate principal from keytab (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [match_principal] (0x1000): Principal matched to the sample (CERBERUSVM$(a)mydomain.COM). (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [select_principal_from_keytab] (0x0200): Selected primary: CERBERUSVM$ (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [select_principal_from_keytab] (0x0200): Selected realm: mydomain.COM (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_set_sasl_options] (0x0100): Option ldap_sasl_authid set to CERBERUSVM$ (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_set_sasl_options] (0x0100): Option ldap_sasl_realm set to mydomain.COM (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [ad_set_search_bases] (0x0100): Search base not set. SSSD will attempt to discover it later, when connecting to the LDAP server. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [ad_dyndns_init] (0x0100): Dynamic DNS updates are off. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [ad_get_auth_options] (0x0100): Option krb5_server set to prodad1.mydomain.com (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [ad_get_auth_options] (0x0100): Option krb5_realm set to mydomain.COM (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [ad_get_auth_options] (0x0100): Option krb5_use_kdcinfo set to true (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [check_lifetime] (0x0200): No lifetime configured. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [check_lifetime] (0x0200): No lifetime configured. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sss_krb5_check_options] (0x0100): No kpasswd server explicitly configured, using the KDC or defaults. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [parse_krb5_map_user] (0x0100): krb5_map_user is empty! (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [dp_target_init] (0x0100): Target [selinux] is not supported by module [ad]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [dp_target_init] (0x0100): Target [hostid] is not supported by module [ad]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sss_write_krb5_localauth_snippet] (0x0200): File for localauth plugin configuration is [/var/lib/sss/pubconf/krb5.include.d/localauth_plugin] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sss_write_krb5_libdefaults_snippet] (0x0200): File for KRB5 kibdefaults configuration is [/var/lib/sss/pubconf/krb5.include.d/krb5_libdefaults] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sss_write_domain_mappings] (0x0200): Mapping file for domain [mydomain.com] is [/var/lib/sss/pubconf/krb5.include.d/domain_realm_mydomain_com] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [ad_set_search_bases] (0x0100): Search base not set. SSSD will attempt to discover it later, when connecting to the LDAP server. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [dp_target_init] (0x0100): Target [session] is not supported by module [ad]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [become_user] (0x0200): Trying to become user [0][0]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [become_user] (0x0200): Already user [0]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [get_server_status] (0x1000): Status of server 'prodad1.mydomain.com' is 'name not resolved' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [get_port_status] (0x1000): Port status of port 0 for server 'prodad1.mydomain.com' is 'neutral' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [get_server_status] (0x1000): Status of server 'prodad1.mydomain.com' is 'name not resolved' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of ' prodad1.mydomain.com' in files (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [set_server_common_status] (0x0100): Marking server 'prodad1.mydomain.com' as 'resolving name' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'prodad1.mydomain.com' in files (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of ' prodad1.mydomain.com' in DNS (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [set_server_common_status] (0x0100): Marking server 'prodad1.mydomain.com' as 'name resolved' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [be_resolve_server_process] (0x0200): Found address for server prodad1.mydomain.com: [192.168.2.13] TTL 10800 (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://prodad1.mydomain.com' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://prodad1.mydomain.com' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap:// prodad1.mydomain.com:389/??base] with fd [19]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [get_naming_context] (0x0200): Using value from [defaultNamingContext] as naming context. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_search_base] to [DC=mydomain,DC=com]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [common_parse_search_base] (0x0100): Search base added: [DEFAULT][DC=mydomain,DC=com][SUBTREE][] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_user_search_base] to [DC=mydomain,DC=com]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [common_parse_search_base] (0x0100): Search base added: [USER][DC=mydomain,DC=com][SUBTREE][] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_group_search_base] to [DC=mydomain,DC=com]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [common_parse_search_base] (0x0100): Search base added: [GROUP][DC=mydomain,DC=com][SUBTREE][] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_netgroup_search_base] to [DC=mydomain,DC=com]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [common_parse_search_base] (0x0100): Search base added: [NETGROUP][DC=mydomain,DC=com][SUBTREE][] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_host_search_base] to [DC=mydomain,DC=com]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [common_parse_search_base] (0x0100): Search base added: [HOST][DC=mydomain,DC=com][SUBTREE][] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [DC=mydomain,DC=com]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [common_parse_search_base] (0x0100): Search base added: [SUDO][DC=mydomain,DC=com][SUBTREE][] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_service_search_base] to [DC=mydomain,DC=com]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [common_parse_search_base] (0x0100): Search base added: [SERVICE][DC=mydomain,DC=com][SUBTREE][] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_set_search_base] (0x0100): Setting option [ldap_autofs_search_base] to [DC=mydomain,DC=com]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [common_parse_search_base] (0x0100): Search base added: [AUTOFS][DC=mydomain,DC=com][SUBTREE][] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [6] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_server_opts_from_rootdse] (0x0100): Will look for schema at [CN=Schema,CN=Configuration,DC=mydomain,DC=com] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [get_server_status] (0x1000): Status of server 'prodad1.mydomain.com' is 'name resolved' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [get_server_status] (0x1000): Status of server 'prodad1.mydomain.com' is 'name resolved' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [be_resolve_server_process] (0x0200): Found address for server prodad1.mydomain.com: [192.168.2.13] TTL 10800 (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [child_sig_handler] (0x1000): Waiting for child [22341]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [child_sig_handler] (0x0100): child [22341] finished successfully. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1547684556 (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: CERBERUSVM$ (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'prodad1.mydomain.com' as 'working' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [set_server_common_status] (0x0100): Marking server 'prodad1.mydomain.com' as 'working' (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [DC=mydomain,DC=com]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [netlogon] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [isMemberOfPartialAttributeSet] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=GidNumber,CN=Schema,CN=Configuration,DC=mydomain,DC=com]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=UidNumber,CN=Schema,CN=Configuration,DC=mydomain,DC=com]. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [flatName] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [trustPartner] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [securityIdentifier] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [trustType] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [trustAttributes] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_add_references] (0x1000): Additional References: ldap://mydomain.com/CN=Configuration,DC=mydomain,DC=com (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [ad_get_slave_domain_done] (0x1000): There are no changes (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [delayed_online_authentication_callback] (0x0200): Backend is online, starting delayed online authentication. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sbus_server_init_new_connection] (0x0200): Entering. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x5632c53a92d0. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [dp_client_init] (0x0100): Set-up Backend ID timeout [0x5632c53af940] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sbus_server_init_new_connection] (0x0200): Entering. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x5632c53ab5d0. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [dp_client_init] (0x0100): Set-up Backend ID timeout [0x5632c539c5a0] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sbus_server_init_new_connection] (0x0200): Entering. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x5632c53b3600. (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [dp_client_init] (0x0100): Set-up Backend ID timeout [0x5632c53b9710] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [dp_client_register] (0x0100): Cancel DP ID timeout [0x5632c53af940] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [dp_client_register] (0x0100): Added Frontend client [PAM] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [dp_client_register] (0x0100): Cancel DP ID timeout [0x5632c539c5a0] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [dp_client_register] (0x0100): Added Frontend client [SSH] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [dp_client_register] (0x0100): Cancel DP ID timeout [0x5632c53b9710] (Wed Jan 16 16:07:36 2019) [sssd[be[mydomain.com]]] [dp_client_register] (0x0100): Added Frontend client [NSS] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [check_ipv4_addr] (0x0200): Loopback IPv4 address 127.0.0.1 (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [check_ipv6_addr] (0x0200): Loopback IPv6 address ::1 (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sudoCommand] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sudoHost] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sudoUser] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sudoOption] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sudoRunAs] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sudoRunAsUser] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sudoRunAsGroup] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sudoNotBefore] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sudoNotAfter] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sudoOrder] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] (Wed Jan 16 16:07:46 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_add_references] (0x1000): Additional References: ldap://mydomain.com/CN=Configuration,DC=mydomain,DC=com (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][name=jlevine(a)mydomain.com] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sshPublicKeys] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userCertificate;binary] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [mail] (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_add_references] (0x1000): Additional References: ldap://mydomain.com/CN=Configuration,DC=mydomain,DC=com (Wed Jan 16 16:08:01 2019) [sssd[be[mydomain.com]]] [dp_req_reply_std] (0x1000): DP Request [Account #0]: Returning [Success]: 0,0,Success (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][name=jlevine(a)mydomain.com] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sss_domain_get_state] (0x1000): Domain mydomain.com is Active (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sshPublicKeys] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userCertificate;binary] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [mail] (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_add_references] (0x1000): Additional References: ldap://mydomain.com/CN=Configuration,DC=mydomain,DC=com (Wed Jan 16 16:09:01 2019) [sssd[be[mydomain.com]]] [dp_req_reply_std] (0x1000): DP Request [Account #1]: Returning [Success]: 0,0,Success ``` Here is sssd_sshd: ``` (Wed Jan 16 16:07:33 2019) [sssd[ssh]] [sss_cmd_get_version] (0x0200): Received client version [0]. (Wed Jan 16 16:07:33 2019) [sssd[ssh]] [sss_cmd_get_version] (0x0200): Offered version [0]. (Wed Jan 16 16:07:33 2019) [sssd[ssh]] [sss_parse_name_for_domains] (0x0200): name 'jsmith' matched without domain, user is jsmith (Wed Jan 16 16:07:33 2019) [sssd[ssh]] [client_recv] (0x0200): Client disconnected! (Wed Jan 16 16:07:33 2019) [sssd[ssh]] [sss_cmd_get_version] (0x0200): Received client version [0]. (Wed Jan 16 16:07:33 2019) [sssd[ssh]] [sss_cmd_get_version] (0x0200): Offered version [0]. (Wed Jan 16 16:07:33 2019) [sssd[ssh]] [sss_parse_name_for_domains] (0x0200): name 'jsmith' matched without domain, user is jsmith (Wed Jan 16 16:07:33 2019) [sssd[ssh]] [client_recv] (0x0200): Client disconnected! (Wed Jan 16 16:07:36 2019) [sssd[ssh]] [handle_requests_after_reconnect] (0x1000): Will handle 0 requests after reconnect ``` Here is a /var/log/secure snippet from sshd: ``` Jan 16 16:07:33 cerberusvm sshd[30533]: debug3: fd 5 is not O_NONBLOCK Jan 16 16:07:33 cerberusvm sshd[30533]: debug1: Forked child 22335. Jan 16 16:07:33 cerberusvm sshd[30533]: debug3: send_rexec_state: entering fd = 8 config len 1005 Jan 16 16:07:33 cerberusvm sshd[30533]: debug3: ssh_msg_send: type 0 Jan 16 16:07:33 cerberusvm sshd[30533]: debug3: send_rexec_state: done Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: oom_adjust_restore Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: Set /proc/self/oom_score_adj to 0 Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: rexec start in 5 out 5 newsock 5 pipe 7 sock 8 Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: inetd sockets after dupping: 3, 3 Jan 16 16:07:33 cerberusvm sshd[22335]: Connection from 192.168.2.111 port 56526 on 192.168.2.17 port 22 Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: Client protocol version 2.0; client software version OpenSSH_7.4 Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: match: OpenSSH_7.4 pat OpenSSH* compat 0x04000000 Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: Local version string SSH-2.0-OpenSSH_7.4 Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: Enabling compatibility mode for protocol 2.0 Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: fd 3 setting O_NONBLOCK Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: ssh_sandbox_init: preparing seccomp filter sandbox Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: Network child is on pid 22336 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: preauth child monitor started Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: SELinux support disabled [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: privsep user:group 74:74 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: permanently_set_uid: 74/74 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: ssh_sandbox_child: setting PR_SET_NO_NEW_PRIVS [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: ssh_sandbox_child: attaching seccomp filter program [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: send packet: type 20 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: SSH2_MSG_KEXINIT sent [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: receive packet: type 20 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: SSH2_MSG_KEXINIT received [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: local server KEXINIT proposal [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: host key algorithms: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: ciphers ctos: chacha20-poly1305(a)openssh.com,aes128-ctr,aes192-ctr,aes256-ctr, aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,blowfish-cbc,cast128-cbc,3des-cbc [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: ciphers stoc: chacha20-poly1305(a)openssh.com,aes128-ctr,aes192-ctr,aes256-ctr, aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,blowfish-cbc,cast128-cbc,3des-cbc [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm(a)openssh.com, hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm(a)openssh.com, hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128(a)openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm(a)openssh.com, hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm(a)openssh.com, hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128(a)openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: compression ctos: none, zlib(a)openssh.com [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: compression stoc: none, zlib(a)openssh.com [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: languages ctos: [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: languages stoc: [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: first_kex_follows 0 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: reserved 0 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: peer client KEXINIT proposal [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1,ext-info-c [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: host key algorithms: ecdsa-sha2-nistp256-cert-v01(a)openssh.com, ecdsa-sha2-nistp384-cert-v01(a)openssh.com, ecdsa-sha2-nistp521-cert-v01(a)openssh.com ,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521, ssh-ed25519-cert-v01@openssh.com,ssh-rsa-cert-v01(a)openssh.com, ssh-dss-cert-v01(a)openssh.com,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa,ssh-dss [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: ciphers ctos: chacha20-poly1305(a)openssh.com,aes128-ctr,aes192-ctr,aes256-ctr, aes128-gcm@openssh.com,aes256-gcm(a)openssh.com,aes128-cbc,aes192-cbc,aes256-cbc [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: ciphers stoc: chacha20-poly1305(a)openssh.com,aes128-ctr,aes192-ctr,aes256-ctr, aes128-gcm@openssh.com,aes256-gcm(a)openssh.com,aes128-cbc,aes192-cbc,aes256-cbc [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm(a)openssh.com, hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm(a)openssh.com, hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128(a)openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm(a)openssh.com, hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm(a)openssh.com, hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128(a)openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: compression ctos: none, zlib(a)openssh.com,zlib [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: compression stoc: none, zlib(a)openssh.com,zlib [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: languages ctos: [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: languages stoc: [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: first_kex_follows 0 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: reserved 0 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: kex: algorithm: curve25519-sha256 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: kex: client->server cipher: chacha20-poly1305(a)openssh.com MAC: <implicit> compression: none [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: kex: server->client cipher: chacha20-poly1305(a)openssh.com MAC: <implicit> compression: none [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: kex: curve25519-sha256 need=64 dh_need=64 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 120 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 121 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_read: checking request 120 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 121 Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: kex: curve25519-sha256 need=64 dh_need=64 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 120 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 121 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_read: checking request 120 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 121 Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: receive packet: type 30 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_key_sign entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 6 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 7 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_read: checking request 6 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_sign Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_sign: hostkey proof signature 0x56075779ced0(100) Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 7 Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: monitor_read: 6 used once, disabling now Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: send packet: type 31 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: send packet: type 21 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: set_newkeys: mode 1 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: rekey after 134217728 blocks [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: SSH2_MSG_NEWKEYS sent [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: expecting SSH2_MSG_NEWKEYS [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: send packet: type 7 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: receive packet: type 21 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: SSH2_MSG_NEWKEYS received [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: set_newkeys: mode 0 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: rekey after 134217728 blocks [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: KEX done [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: receive packet: type 5 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: send packet: type 6 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: receive packet: type 50 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: userauth-request for user jsmith service ssh-connection method none [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: attempt 0 failures 0 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_getpwnamallow entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 8 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 9 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_read: checking request 8 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_pwnamallow Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: parse_server_config: config reprocess config len 1005 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: checking match for 'User mydomain,nagios,ansible,root' user jsmith host 192.168.2.111 addr 192.168.2.111 laddr 192.168.2.17 lport 22 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: match not found Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: auth2_setup_methods_lists: checking methods Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: authentication methods list 0: publickey,keyboard-interactive Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 9 Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: monitor_read: 8 used once, disabling now Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: input_userauth_request: setting up authctxt for jsmith [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_start_pam entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 100 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_inform_authserv entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 4 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_inform_authrole entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 80 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: auth2_setup_methods_lists: checking methods [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: authentication methods list 0: publickey,keyboard-interactive [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: Unrecognized authentication method name: none [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: userauth_finish: failure partial=0 next methods="publickey" [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: send packet: type 51 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_read: checking request 100 Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: PAM: initializing for "jsmith" Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: PAM: setting PAM_RHOST to "192.168.2.111" Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: PAM: setting PAM_TTY to "ssh" Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: monitor_read: 100 used once, disabling now Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_read: checking request 4 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_authserv: service=ssh-connection, style= Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: monitor_read: 4 used once, disabling now Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_read: checking request 80 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_authrole: role= Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: monitor_read: 80 used once, disabling now Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: receive packet: type 50 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: userauth-request for user jsmith service ssh-connection method publickey [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: attempt 1 failures 0 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: input_userauth_request: try method publickey [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: userauth_pubkey: test whether pkalg/pkblob are acceptable for RSA SHA256:Wtul7zrgzlGGNe4U2EZp5fRybKeSCGbjuzJxIYv0l7o [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_key_allowed entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 22 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 23 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_read: checking request 22 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_keyallowed entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_keyallowed: key_from_blob: 0x5607577a1bc0 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: sshd_selinux_setup_variables: setting execution context Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: subprocess: AuthorizedKeysCommand command "/usr/bin/sss_ssh_authorizedkeys jsmith" running as root Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: temporarily_use_uid: 0/0 (e=0/0) Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: restore_uid: 0/0 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: subprocess: AuthorizedKeysCommand pid 22337 Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: temporarily_use_uid: 0/0 (e=0/0) Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: matching key found: file /usr/bin/sss_ssh_authorizedkeys, line 2 RSA SHA256:Wtul7zrgzlGGNe4U2EZp5fRybKeSCGbjuzJxIYv0l7o Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: restore_uid: 0/0 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_keyallowed: key 0x5607577a1bc0 is allowed Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 23 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: send packet: type 60 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: userauth_pubkey: authenticated 0 pkalg rsa-sha2-512 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: Postponed publickey for jsmith from 192.168.2.111 port 56526 ssh2 [preauth] Jan 16 16:07:33 cerberusvm sshd[32270]: debug2: channel 0: rcvd adjust 49175 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: receive packet: type 50 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: userauth-request for user jsmith service ssh-connection method publickey [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: attempt 2 failures 0 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: input_userauth_request: try method publickey [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: userauth_pubkey: have signature for RSA SHA256:Wtul7zrgzlGGNe4U2EZp5fRybKeSCGbjuzJxIYv0l7o [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_key_allowed entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 22 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 23 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_read: checking request 22 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_keyallowed entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_keyallowed: key_from_blob: 0x5607577b1e00 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: sshd_selinux_setup_variables: setting execution context Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: subprocess: AuthorizedKeysCommand command "/usr/bin/sss_ssh_authorizedkeys jsmith" running as root Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: temporarily_use_uid: 0/0 (e=0/0) Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: restore_uid: 0/0 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: subprocess: AuthorizedKeysCommand pid 22338 Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: temporarily_use_uid: 0/0 (e=0/0) Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: matching key found: file /usr/bin/sss_ssh_authorizedkeys, line 2 RSA SHA256:Wtul7zrgzlGGNe4U2EZp5fRybKeSCGbjuzJxIYv0l7o Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: restore_uid: 0/0 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_keyallowed: key 0x5607577b1e00 is allowed Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 23 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_key_verify entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 24 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_key_verify: waiting for MONITOR_ANS_KEYVERIFY [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 25 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_read: checking request 24 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_keyverify: key 0x5607577ac580 signature verified Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 25 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: auth2_update_methods_lists: updating methods list after "publickey" Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: authentication methods list 0 remaining: "keyboard-interactive" Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_child_preauth: method publickey: partial Jan 16 16:07:33 cerberusvm sshd[22335]: Partial publickey for jsmith from 192.168.2.111 port 56526 ssh2: RSA SHA256:Wtul7zrgzlGGNe4U2EZp5fRybKeSCGbjuzJxIYv0l7o Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: userauth_pubkey: authenticated 1 pkalg rsa-sha2-512 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: auth2_update_methods_lists: updating methods list after "publickey" [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: authentication methods list 0 remaining: "keyboard-interactive" [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: userauth_finish: failure partial=1 next methods="keyboard-interactive" [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: send packet: type 51 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: receive packet: type 50 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: userauth-request for user jsmith service ssh-connection method keyboard-interactive [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: attempt 3 failures 0 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: input_userauth_request: try method keyboard-interactive [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: keyboard-interactive devs [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: auth2_challenge: user=jsmith devs= [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: kbdint_alloc: devices 'pam' [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: auth2_challenge_start: devices pam [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: kbdint_next_device: devices <empty> [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug1: auth2_challenge_start: trying authentication method 'pam' [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_sshpam_init_ctx [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 104 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_sshpam_init_ctx: waiting for MONITOR_ANS_PAM_INIT_CTX [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 105 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_read: checking request 104 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_pam_init_ctx Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: PAM: sshpam_init_ctx entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 105 Jan 16 16:07:33 cerberusvm sshd[22335]: debug2: monitor_read: 104 used once, disabling now Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_sshpam_query [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 106 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_sshpam_query: waiting for MONITOR_ANS_PAM_QUERY [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 107 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: monitor_read: checking request 106 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_answer_pam_query Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: PAM: sshpam_query entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: ssh_msg_recv entering Jan 16 16:07:33 cerberusvm sshd[22339]: debug3: PAM: sshpam_thread_conv entering, 1 messages Jan 16 16:07:33 cerberusvm sshd[22339]: debug3: ssh_msg_send: type 2 Jan 16 16:07:33 cerberusvm sshd[22339]: debug3: ssh_msg_recv entering Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 107 Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: mm_sshpam_query: pam_query returned 0 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: debug3: send packet: type 60 [preauth] Jan 16 16:07:33 cerberusvm sshd[22335]: Postponed keyboard-interactive for jsmith from 192.168.2.111 port 56526 ssh2: RSA SHA256:Wtul7zrgzlGGNe4U2EZp5fRybKeSCGbjuzJxIYv0l7o [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: receive packet: type 61 [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_sshpam_respond [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 108 [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_sshpam_respond: waiting for MONITOR_ANS_PAM_RESPOND [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 109 [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: monitor_read: checking request 108 Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_answer_pam_respond Jan 16 16:07:35 cerberusvm sshd[22335]: debug2: PAM: sshpam_respond entering, 1 responses Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: ssh_msg_send: type 6 Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 109 Jan 16 16:07:35 cerberusvm sshd[22335]: debug2: monitor_read: 108 used once, disabling now Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_sshpam_respond: pam_respond returned 1 [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_sshpam_query [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 106 [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_sshpam_query: waiting for MONITOR_ANS_PAM_QUERY [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 107 [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: monitor_read: checking request 106 Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: mm_answer_pam_query Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: PAM: sshpam_query entering Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: ssh_msg_recv entering Jan 16 16:07:35 cerberusvm sshd[22339]: debug3: PAM: sshpam_thread_conv entering, 1 messages Jan 16 16:07:35 cerberusvm sshd[22339]: debug3: ssh_msg_send: type 4 Jan 16 16:07:35 cerberusvm sshd[22339]: Successful Duo login for 'jsmith' from 192.168.2.111 Jan 16 16:07:35 cerberusvm sshd[22339]: debug1: do_pam_account: called Jan 16 16:07:35 cerberusvm sshd[22335]: debug3: ssh_msg_recv entering Jan 16 16:09:05 cerberusvm sshd[22339]: debug3: PAM: do_pam_account pam_acct_mgmt = 9 (Authentication service cannot retrieve authentication info) Jan 16 16:09:05 cerberusvm sshd[22339]: debug3: ssh_msg_send: type 13 Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: PAM: User account has expired Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 107 Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_sshpam_query: pam_query returned 0 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: send packet: type 60 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: Postponed keyboard-interactive/pam for jsmith from 192.168.2.111 port 56526 ssh2 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: receive packet: type 61 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_sshpam_respond [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 108 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_sshpam_respond: waiting for MONITOR_ANS_PAM_RESPOND [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 109 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: monitor_read: checking request 108 Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_answer_pam_respond Jan 16 16:09:05 cerberusvm sshd[22335]: debug2: PAM: sshpam_respond entering, 0 responses Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 109 Jan 16 16:09:05 cerberusvm sshd[22335]: debug2: monitor_read: 108 used once, disabling now Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_sshpam_respond: pam_respond returned -1 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug2: auth2_challenge_start: devices <empty> [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_sshpam_free_ctx [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 110 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_sshpam_free_ctx: waiting for MONITOR_ANS_PAM_FREE_CTX [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 111 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: monitor_read: checking request 110 Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_answer_pam_free_ctx Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: PAM: sshpam_free_ctx entering Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: PAM: sshpam_thread_cleanup entering Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 111 Jan 16 16:09:05 cerberusvm sshd[22335]: debug2: monitor_read: 110 used once, disabling now Jan 16 16:09:05 cerberusvm sshd[22335]: Failed keyboard-interactive/pam for jsmith from 192.168.2.111 port 56526 ssh2 Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: userauth_finish: failure partial=0 next methods="keyboard-interactive" [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: send packet: type 51 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: receive packet: type 50 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: userauth-request for user jsmith service ssh-connection method keyboard-interactive [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: attempt 4 failures 1 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug2: input_userauth_request: try method keyboard-interactive [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: keyboard-interactive devs [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: auth2_challenge: user=jsmith devs= [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: kbdint_alloc: devices 'pam' [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug2: auth2_challenge_start: devices pam [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug2: kbdint_next_device: devices <empty> [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: auth2_challenge_start: trying authentication method 'pam' [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_sshpam_init_ctx [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 104 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_sshpam_init_ctx: waiting for MONITOR_ANS_PAM_INIT_CTX [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 105 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: monitor_read: checking request 104 Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_answer_pam_init_ctx Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: PAM: sshpam_init_ctx entering Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 105 Jan 16 16:09:05 cerberusvm sshd[22335]: debug2: monitor_read: 104 used once, disabling now Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_sshpam_init_ctx: pam_init_ctx failed [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: userauth_finish: failure partial=0 next methods="keyboard-interactive" [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: send packet: type 51 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: receive packet: type 50 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: userauth-request for user jsmith service ssh-connection method keyboard-interactive [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: attempt 5 failures 2 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug2: input_userauth_request: try method keyboard-interactive [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: keyboard-interactive devs [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: auth2_challenge: user=jsmith devs= [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: kbdint_alloc: devices 'pam' [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug2: auth2_challenge_start: devices pam [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug2: kbdint_next_device: devices <empty> [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: auth2_challenge_start: trying authentication method 'pam' [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_sshpam_init_ctx [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_send entering: type 104 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_sshpam_init_ctx: waiting for MONITOR_ANS_PAM_INIT_CTX [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_receive_expect entering: type 105 [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_receive entering [preauth] Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: mm_request_receive entering Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: monitor_read: checking request 104 Jan 16 16:09:05 cerberusvm sshd[22335]: fatal: monitor_read: unpermitted request 104 Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: do_cleanup Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: PAM: cleanup Jan 16 16:09:05 cerberusvm sshd[22335]: debug3: PAM: sshpam_thread_cleanup entering Jan 16 16:09:05 cerberusvm sshd[22335]: debug1: Killing privsep child 22336 ``` Now the interesting thing is that when I check `journalctl -u sssd.service`, at the same time this is starting (16:07:35), sssd appears to crash and restart: ``` Jan 16 16:07:35 cerberusvm.mydomain.com sssd[be[mydomain.com]][22340]: Starting up Jan 16 16:07:36 cerberusvm.mydomain.com sssd_be[22340]: GSSAPI client step 1 Jan 16 16:07:36 cerberusvm.mydomain.com sssd_be[22340]: GSSAPI client step 1 Jan 16 16:07:36 cerberusvm.mydomain.com sssd_be[22340]: GSSAPI client step 1 Jan 16 16:07:36 cerberusvm.mydomain.com sssd_be[22340]: GSSAPI client step 2 ``` This made me look at dmesg, and sssd has been causing a ton of segfaults: ``` [Wed Jan 16 04:55:13 2019] traps: sssd_be[25969] general protection ip:7fdcd54ab766 sp:7fff5f1ce570 error:0 in libtalloc.so.2.1.13[7fdcd54a6000+e000] [Wed Jan 16 06:28:46 2019] traps: sssd_be[10849] general protection ip:7f9601987766 sp:7fffb5f35f10 error:0 in libtalloc.so.2.1.13[7f9601982000+e000] [Wed Jan 16 10:34:01 2019] traps: sssd_be[26901] general protection ip:7f8814b17766 sp:7fff46e2ab40 error:0 in libtalloc.so.2.1.13[7f8814b12000+e000] [Wed Jan 16 10:38:14 2019] traps: sssd_be[28969] general protection ip:7fab7b4a0766 sp:7fff85e9e2f0 error:0 in libtalloc.so.2.1.13[7fab7b49b000+e000] [Wed Jan 16 11:15:09 2019] sssd_be[3446]: segfault at 5646ffffffa0 ip 00007f9799f1f766 sp 00007ffd113922d0 error 4 in libtalloc.so.2.1.13[7f9799f1a000+e000] [Wed Jan 16 11:26:01 2019] sssd_be[4217]: segfault at ffffffffffffffa1 ip 00007f72eadb1766 sp 00007fffdac4d3c0 error 5 in libtalloc.so.2.1.13[7f72eadac000+e000] [Wed Jan 16 11:28:58 2019] sssd_be[6050]: segfault at b403 ip 00007f91435bb766 sp 00007fff278853b0 error 4 in libtalloc.so.2.1.13[7f91435b6000+e000] [Wed Jan 16 13:25:22 2019] traps: sssd_be[24797] general protection ip:7f63511b8766 sp:7ffcef433c90 error:0 in libtalloc.so.2.1.13[7f63511b3000+e000] [Wed Jan 16 13:41:34 2019] sssd_be[29033]: segfault at ffffffffffffffa3 ip 00007f65ef819766 sp 00007fff1827f8f0 error 5 in libtalloc.so.2.1.13[7f65ef814000+e000] [Wed Jan 16 13:44:57 2019] traps: sssd_be[29224] general protection ip:7fa76a909766 sp:7ffde8f7fc60 error:0 in libtalloc.so.2.1.13[7fa76a904000+e000] [Wed Jan 16 14:59:33 2019] sssd_be[6553]: segfault at ffffffffffffffa5 ip 00007f7af1396766 sp 00007ffcd4876d70 error 5 in libtalloc.so.2.1.13[7f7af1391000+e000] [Wed Jan 16 15:39:22 2019] sssd_be[19999]: segfault at 20 ip 00007f31511fa766 sp 00007fffbe331c40 error 4 in libtalloc.so.2.1.13[7f31511f5000+e000] [Wed Jan 16 15:41:36 2019] sssd_be[20245]: segfault at ffffffffffffffe8 ip 00007f0a9fe82766 sp 00007ffd9374afb0 error 5 in libtalloc.so.2.1.13[7f0a9fe7d000+e000] [Wed Jan 16 15:44:43 2019] sssd_be[21086]: segfault at ffffffffffffffaa ip 00007f442b1f6766 sp 00007fff2341ccb0 error 5 in libtalloc.so.2.1.13[7f442b1f1000+e000] [Wed Jan 16 15:50:24 2019] sssd_be[21155]: segfault at ffffffffffffffb0 ip 00007f4df0fcb766 sp 00007ffcecacbf60 error 5 in libtalloc.so.2.1.13[7f4df0fc6000+e000] [Wed Jan 16 16:05:56 2019] sssd_be[24929]: segfault at 501000da0 ip 00007faf383d3766 sp 00007ffc3ea27330 error 4 in libtalloc.so.2.1.13[7faf383ce000+e000] [Wed Jan 16 16:23:51 2019] sssd_be[25298]: segfault at 90 ip 00007fdadd768766 sp 00007fff09a8fe70 error 4 in libtalloc.so.2.1.13[7fdadd763000+e000] [Wed Jan 16 16:29:07 2019] sssd_be[28863]: segfault at 7fba0d3ea0b0 ip 00007fba65f7c766 sp 00007ffc96a709e0 error 4 in libtalloc.so.2.1.13[7fba65f77000+e000] [Wed Jan 16 16:29:24 2019] traps: sssd_be[28885] general protection ip:7f9492228766 sp:7fff07ffd300 error:0 in libtalloc.so.2.1.13[7f9492223000+e000] ``` Although none specifically line up with the logs above, these logs are the cleanest versions of each I could put together and are best representative of the issue, but other failures which align with the segfault times are essentially the same (and all correlate with service restarts in /var/log/messages). If it is vital to see a log associated with one of these segfaults, let me know and I can try to assemble one. Thanks On Wed, Jan 16, 2019 at 3:12 PM Jordan Castillo <jordantcastillo(a)gmail.com&gt; wrote: > Here are my log files for both the good and bad attempts. >

_______________________________________________ sssd-users mailing list -- sssd-users(a)lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave(a)lists.fedorahosted.org Fedora Code of Conduct: https://getfedora.org/code-of-conduct.html List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/sssd-users@lists.fedorahoste...

Hi Sumit, Thanks for your response. I am running CentOS 7.4.1708 and installed sssd via yum. I have sssd-1.16.2-13.el7.x86_64 currently installed. None of the libraries mentioned are showing available updates. Here are the versions I see installed for them: libtalloc-2.1.13-1.el7.x86_64 libtdb-1.3.15-1.el7.x86_64 libtevent-0.9.36-1.el7.x86_64 libldb-1.3.4-1.el7.x86_64

Hi Sumit, The server was running samba-client-libs-4.6.2-12. I did a yum update on samba-client-libs, samba-common-tools, samba-common, samba-common-libs, and samba-libs. Now it is running running 4.8.3-4 for all of those packages and I can no longer reproduce the issue. It appears to be fixed. Thank you so much for your help.