Hey All, Apologies in advance for the long email.
I am having an issue with password resets via sshd and usermin. I think if I can get the sshd working again the usermin side will fall into place again. This used to work about a week or two ago, but I'm not sure what changed to break it. A new kernel update from RH was applied but even if I boot to the old kernel the issue persists. Attempts to connect over ssh (or anywhere else allowed by HBAC policy) works great except for users with expired passwords. When the client server tries to reset the password it fails. I was able to get the password change to succeed by setting the sshd to ChallengeResponse yes which seems very strange to me. Everything was run with setenforce 0 to make sure there was no issues from selinux. If anyone has any ideas on what I could try as a next step it would be greatly appreciated! V/r, David auth is the freeipa server while webserver is the server acting as the client, both are RHEL6.6 Client Server versions: ipa-client.x86_64 3.0.0-42.el6 ipa-python.x86_64 3.0.0-42.el6 libipa_hbac.x86_64 1.11.6-30.el6_6.4 libipa_hbac-python.x86_64 1.11.6-30.el6_6.4 python-iniparse.noarch 0.3.1-2.1.el6 sssd-ipa.x86_64 1.11.6-30.el6_6.4 IPA Server versions: ipa-admintools.x86_64 3.0.0-42.el6 ipa-client.x86_64 3.0.0-42.el6 ipa-pki-ca-theme.noarch 9.0.3-7.el6 ipa-pki-common-theme.noarch 9.0.3-7.el6 ipa-python.x86_64 3.0.0-42.el6 ipa-server.x86_64 3.0.0-42.el6 ipa-server-selinux.x86_64 3.0.0-42.el6 libipa_hbac.x86_64 1.11.6-30.el6_6.4 libipa_hbac-python.x86_64 1.11.6-30.el6_6.4 python-iniparse.noarch 0.3.1-2.1.el6 sssd-ipa.x86_64 1.11.6-30.el6_6.4 My sshd pam file on the client server: [root@webserver pam.d]# cat sshd | grep -v ^# auth required pam_sepermit.so auth include password-auth account required pam_nologin.so account include password-auth password include password-auth session required pam_selinux.so close session required pam_loginuid.so session required pam_selinux.so open env_params session optional pam_keyinit.so force revoke session include password-auth My password-auth on the client server: [root@webserver pam.d]# cat password-auth | grep -v ^# auth required pam_env.so auth sufficient pam_sss.so auth sufficient pam_unix.so try_first_pass auth required pam_deny.so account [default=bad success=ok user_unknown=ignore] pam_sss.so account required pam_unix.so account required pam_permit.so password required pam_cracklib.so retry=3 minlen=14 dcredit=-1 ucredit=-1 ocredit=-1 lcredit=-1 difok=3 maxrepeat=3 password sufficient pam_sss.so use_authtok password sufficient pam_unix.so sha512 shadow try_first_pass use_authtok remember=24 password required pam_deny.so session optional pam_sss.so session required pam_unix.so Attempting to ssh in first with ChallengeResponse set to no, then yes [root@auth /]# ssh dummy@192.168.1.6 dummy@192.168.1.6's password: Password expired. Change your password now. Last login: Wed Jul 29 09:08:13 2015 from auth.mydomain.com WARNING: Your password has expired. You must change your password now and login again! Changing password for user dummy. Current Password: New password: Retype new password: passwd: Authentication token manipulation error Connection to 192.168.1.6 closed. [root@auth /]# ssh dummy@192.168.1.6 Password: Password expired. Change your password now. Current Password: New password: Retype new password: Last login: Wed Jul 29 09:11:19 2015 from auth.mydomain.com [dummy@webserver ~]$ /var/log/secure record of the activity: Jul 29 09:11:19 webserver sshd[26823]: pam_sss(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=auth.mydomain.com user=dummy Jul 29 09:11:19 webserver sshd[26823]: pam_sss(sshd:auth): received for user dummy: 12 (Authentication token is no longer valid; new one required) Jul 29 09:11:19 webserver sshd[26823]: pam_sss(sshd:account): User info message: Password expired. Change your password now. Jul 29 09:11:19 webserver sshd[26823]: Accepted password for dummy from 192.168.1.5 port 43656 ssh2 Jul 29 09:11:19 webserver sshd[26823]: pam_unix(sshd:session): session opened for user dummy by (uid=0) Jul 29 09:11:28 webserver passwd: pam_sss(passwd:chauthtok): Password change failed for user dummy: 15 (Authentication service cannot retrieve user credentials) Jul 29 09:11:38 webserver passwd: pam_unix(passwd:chauthtok): user "dummy" does not exist in /etc/passwd Jul 29 09:11:39 webserver sshd[26823]: pam_unix(sshd:session): session closed for user dummy Jul 29 09:12:01 webserver crond[26836]: pam_unix(crond:session): session opened for user root by (uid=0) Jul 29 09:12:01 webserver crond[26837]: pam_unix(crond:session): session opened for user root by (uid=0) Jul 29 09:12:01 webserver CROND[26836]: pam_unix(crond:session): session closed for user root Jul 29 09:12:01 webserver CROND[26837]: pam_unix(crond:session): session closed for user root Jul 29 09:12:04 webserver sshd[26784]: Received signal 15; terminating. Jul 29 09:12:05 webserver sshd[26865]: Server listening on 0.0.0.0 port 22. Jul 29 09:12:16 webserver sshd[26874]: pam_sss(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=auth.mydomain.com user=dummy Jul 29 09:12:16 webserver sshd[26874]: pam_sss(sshd:auth): received for user dummy: 12 (Authentication token is no longer valid; new one required) Jul 29 09:12:16 webserver sshd[26874]: pam_sss(sshd:account): User info message: Password expired. Change your password now. Jul 29 09:12:33 webserver sshd[26869]: Accepted keyboard-interactive/pam for dummy from 192.168.1.5 port 43657 ssh2 Jul 29 09:12:34 webserver sshd[26869]: pam_unix(sshd:session): session opened for user dummy by (uid=0) Log of the activity from /var/log/sssd/sssd_mydomain.com.log with debug_level=6 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_get_account_info] (0x0100): Got request for [3][1][name=dummy] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_req_set_domain] (0x0400): Changing request domain from [mydomain.com] to [mydomain.com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [cn=accounts,dc=mydomain,dc=com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(uid=dummy)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Save user (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_attrs_get_sid_str] (0x0080): No [objectSIDString] attribute while id-mapping. [0][Success] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Processing user dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Adding original memberOf attributes to [dummy]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Adding user principal [du...@mydomain.com] to attributes of [dummy]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Storing info for user dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_has_deref_support] (0x0400): The server supports deref method OpenLDAP (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=ipausers,cn=groups,cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=employee,cn=groups,cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][ipauniqueid=61d77496-1506-11e5-aae7-00505689b3d1,cn=hbac,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_initgr_nested_search] (0x0040): Search for group ipauniqueid=61d77496-1506-11e5-aae7-00505689b3d1,cn=hbac,dc=mydomain,dc=com, returned 0 results. Skipping (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=sshldapusers,cn=groups,cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object ipausers (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object employee (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object sshldapusers (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_groups_next_base] (0x0400): Searching for groups with base [cn=accounts,dc=mydomain,dc=com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(gidNumber=895400028)(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_groups_process] (0x0400): Search for groups, returned 1 results. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_has_deref_support] (0x0400): The server supports deref method OpenLDAP (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_nested_group_recv] (0x0400): 0 users found in the hash table (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_nested_group_recv] (0x0400): 1 groups found in the hash table (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_attrs_get_sid_str] (0x0080): No [objectSIDString] attribute while id-mapping. [0][Success] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_save_group] (0x0400): Processing group dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_process_ghost_members] (0x0400): The group has 0 members (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_process_ghost_members] (0x0400): Group has 0 members (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_save_group] (0x0400): Storing info for group dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_save_grpmem] (0x0400): Processing group dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_save_grpmem] (0x0400): No members for group [dummy] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_req_set_domain] (0x0400): Changing request domain from [mydomain.com] to [mydomain.com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Got request with the following data (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): domain: mydomain.com (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): user: dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): service: sshd (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): tty: ssh (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): ruser: (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): rhost: auth.mydomain.com (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): authtok type: 1 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): priv: 1 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): cli_pid: 27457 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [switch_creds] (0x0200): Switch user to [895400028][895400028]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [switch_creds] (0x0200): Switch user to [0][0]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_resolve_server_process] (0x0200): Found address for server auth.mydomain.com: [192.168.1.5] TTL 86400 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://auth.mydomain.com' (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [write_pipe_handler] (0x0400): All data has been sent! (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [read_pipe_handler] (0x0400): EOF received, client finished (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [switch_creds] (0x0200): Switch user to [895400028][895400028]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [switch_creds] (0x0200): Switch user to [0][0]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 12, <NULL>) [Success] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Sending result [12][mydomain.com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Sent result [12][mydomain.com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [child_sig_handler] (0x0100): child [27462] finished successfully. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_req_set_domain] (0x0400): Changing request domain from [mydomain.com] to [mydomain.com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Got request with the following data (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): command: PAM_ACCT_MGMT (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): domain: mydomain.com (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): user: dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): service: sshd (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): tty: ssh (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): ruser: (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): rhost: auth.mydomain.com (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): authtok type: 0 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): priv: 1 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): cli_pid: 27457 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_access_send] (0x0400): Performing access check for user [dummy] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_account_expired_rhds] (0x0400): Performing RHDS access check for user [dummy] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectClass=ipaHost)(fqdn=webserver.mydomain.com ))][cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_has_deref_support] (0x0400): The server supports deref method OpenLDAP (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_x_deref_search_send] (0x0400): Dereferencing entry [fqdn= webserver.mydomain.com,cn=computers,cn=accounts,dc=mydomain,dc=com] using OpenLDAP deref (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [no filter][fqdn=webserver.mydomain.com ,cn=computers,cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_x_deref_parse_entry] (0x0400): Got deref control (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_x_deref_parse_entry] (0x0400): All deref results from a single control parsed (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [ipa_hostgroup_info_done] (0x0200): No host groups were dereferenced (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [ipa_hbac_service_info_next] (0x0400): Sending request for next search base: [cn=hbac,dc=mydomain,dc=com][2][(objectClass=ipaHBACService)] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectClass=ipaHBACService)][cn=hbac,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [ipa_hbac_servicegroup_info_next] (0x0400): Sending request for next search base: [cn=hbac,dc=mydomain,dc=com][2][(objectClass=ipaHBACServiceGroup)] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectClass=ipaHBACServiceGroup)][cn=hbac,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [ipa_hbac_rule_info_next] (0x0400): Sending request for next search base: [cn=hbac,dc=mydomain,dc=com][2][(&(objectclass=ipaHBACRule)(ipaenabledflag=TRUE)(|(hostCategory=all)(memberHost=fqdn= webserver.mydomain.com ,cn=computers,cn=accounts,dc=mydomain,dc=com)(memberHost=ipauniqueid=2f86c3d6-145f-11e5-9d77-00505689b3d1,cn=hbac,dc=mydomain,dc=com)(memberHost=ipauniqueid=61d77496-1506-11e5-aae7-00505689b3d1,cn=hbac,dc=mydomain,dc=com)))] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectclass=ipaHBACRule)(ipaenabledflag=TRUE)(|(hostCategory=all)(memberHost=fqdn= webserver.mydomain.com ,cn=computers,cn=accounts,dc=mydomain,dc=com)(memberHost=ipauniqueid=2f86c3d6-145f-11e5-9d77-00505689b3d1,cn=hbac,dc=mydomain,dc=com)(memberHost=ipauniqueid=61d77496-1506-11e5-aae7-00505689b3d1,cn=hbac,dc=mydomain,dc=com)))][cn=hbac,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [hbac_shost_attrs_to_rule] (0x0400): Processing source hosts for rule [customer] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [hbac_get_category] (0x0200): Category is set to 'all'. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [hbac_get_category] (0x0200): Category is set to 'all'. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [hbac_shost_attrs_to_rule] (0x0400): Processing source hosts for rule [admins] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [hbac_shost_attrs_to_rule] (0x0400): Processing source hosts for rule [employee] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [hbac_user_attrs_to_rule] (0x0020): [uid=vascan,cn=users,cn=accounts,dc=mydomain,dc=com] does not map to either a user or group. Skipping (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [hbac_get_category] (0x0200): Category is set to 'all'. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [hbac_shost_attrs_to_rule] (0x0400): Processing source hosts for rule [vascan] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [ipa_hbac_evaluate_rules] (0x0080): Access granted by HBAC rule [employee] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, <NULL>) [Success] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [ipa_get_selinux_send] (0x0400): Retrieving SELinux user mapping (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(cn=ipaConfig)(objectClass=ipaGuiConfig))][cn=etc,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [ipa_selinux_get_maps_next] (0x0400): Trying to fetch SELinux maps with following parameters: [2][(&(objectclass=ipaselinuxusermap)(ipaEnabledFlag=TRUE))][cn=selinux,dc=mydomain,dc=com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectclass=ipaselinuxusermap)(ipaEnabledFlag=TRUE))][cn=selinux,dc=mydomain,dc=com]. (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [ipa_selinux_get_maps_done] (0x0400): No SELinux user maps found! (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, Success) [Success] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Sending result [0][mydomain.com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Sent result [0][mydomain.com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_req_set_domain] (0x0400): Changing request domain from [mydomain.com] to [mydomain.com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Got request with the following data (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): command: PAM_SETCRED (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): domain: mydomain.com (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): user: dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): service: sshd (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): tty: ssh (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): ruser: (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): rhost: auth.mydomain.com (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): authtok type: 0 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): priv: 1 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): cli_pid: 27457 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Sending result [0][mydomain.com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_req_set_domain] (0x0400): Changing request domain from [mydomain.com] to [mydomain.com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Got request with the following data (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): command: PAM_OPEN_SESSION (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): domain: mydomain.com (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): user: dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): service: sshd (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): tty: ssh (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): ruser: (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): rhost: auth.mydomain.com (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): authtok type: 0 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): priv: 1 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): cli_pid: 27457 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Sending result [0][mydomain.com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_req_set_domain] (0x0400): Changing request domain from [mydomain.com] to [mydomain.com] (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Got request with the following data (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): command: PAM_SETCRED (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): domain: mydomain.com (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): user: dummy (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): service: sshd (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): tty: ssh (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): ruser: (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): rhost: auth.mydomain.com (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): authtok type: 0 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): priv: 0 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): cli_pid: 27463 (Wed Jul 29 09:37:36 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Sending result [0][mydomain.com] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_get_account_info] (0x0100): Got request for [3][1][name=dummy] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_req_set_domain] (0x0400): Changing request domain from [mydomain.com] to [mydomain.com] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [cn=accounts,dc=mydomain,dc=com] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(uid=dummy)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Save user (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_attrs_get_sid_str] (0x0080): No [objectSIDString] attribute while id-mapping. [0][Success] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object dummy (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Processing user dummy (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Adding original memberOf attributes to [dummy]. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Adding user principal [du...@mydomain.com] to attributes of [dummy]. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Storing info for user dummy (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object dummy (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_has_deref_support] (0x0400): The server supports deref method OpenLDAP (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=ipausers,cn=groups,cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=employee,cn=groups,cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][ipauniqueid=61d77496-1506-11e5-aae7-00505689b3d1,cn=hbac,dc=mydomain,dc=com]. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_initgr_nested_search] (0x0040): Search for group ipauniqueid=61d77496-1506-11e5-aae7-00505689b3d1,cn=hbac,dc=mydomain,dc=com, returned 0 results. Skipping (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=sshldapusers,cn=groups,cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object ipausers (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object employee (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object sshldapusers (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_groups_next_base] (0x0400): Searching for groups with base [cn=accounts,dc=mydomain,dc=com] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(gidNumber=895400028)(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_groups_process] (0x0400): Search for groups, returned 1 results. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_has_deref_support] (0x0400): The server supports deref method OpenLDAP (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_nested_group_recv] (0x0400): 0 users found in the hash table (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_nested_group_recv] (0x0400): 1 groups found in the hash table (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_attrs_get_sid_str] (0x0080): No [objectSIDString] attribute while id-mapping. [0][Success] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object dummy (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_save_group] (0x0400): Processing group dummy (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_process_ghost_members] (0x0400): The group has 0 members (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_process_ghost_members] (0x0400): Group has 0 members (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_save_group] (0x0400): Storing info for group dummy (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object dummy (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_save_grpmem] (0x0400): Processing group dummy (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [sdap_save_grpmem] (0x0400): No members for group [dummy] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_req_set_domain] (0x0400): Changing request domain from [mydomain.com] to [mydomain.com] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Got request with the following data (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): command: PAM_CHAUTHTOK_PRELIM (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): domain: mydomain.com (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): user: dummy (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): service: passwd (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): tty: pts/1 (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): ruser: (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): rhost: (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): authtok type: 1 (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): priv: 0 (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): cli_pid: 27464 (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [krb5_auth_send] (0x0100): No ccache file for user [dummy] found. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_resolve_server_process] (0x0200): Found address for server auth.mydomain.com: [192.168.1.5] TTL 86400 (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [write_pipe_handler] (0x0400): All data has been sent! (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [read_pipe_handler] (0x0400): EOF received, client finished (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, <NULL>) [Success] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Sending result [0][mydomain.com] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Sent result [0][mydomain.com] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_req_set_domain] (0x0400): Changing request domain from [mydomain.com] to [mydomain.com] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Got request with the following data (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): command: PAM_CHAUTHTOK (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): domain: mydomain.com (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): user: dummy (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): service: passwd (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): tty: pts/1 (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): ruser: (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): rhost: (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): authtok type: 1 (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): priv: 0 (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): cli_pid: 27464 (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [krb5_auth_send] (0x0100): No ccache file for user [dummy] found. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_resolve_server_process] (0x0200): Found address for server auth.mydomain.com: [192.168.1.5] TTL 86400 (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [write_pipe_handler] (0x0400): All data has been sent! (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [child_sig_handler] (0x0020): waitpid did not found a child with changed status. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [child_sig_handler] (0x0100): child [27467] finished successfully. (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [read_pipe_handler] (0x0400): EOF received, client finished (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 15, <NULL>) [Success] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Sending result [15][mydomain.com] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [be_pam_handler_callback] (0x0100): Sent result [15][mydomain.com] (Wed Jul 29 09:37:42 2015) [sssd[be[mydomain.com]]] [child_sig_handler] (0x0100): child [27468] finished successfully. (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [be_get_account_info] (0x0100): Got request for [3][1][name=dummy] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [be_req_set_domain] (0x0400): Changing request domain from [mydomain.com] to [mydomain.com] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [cn=accounts,dc=mydomain,dc=com] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(uid=dummy)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Save user (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_attrs_get_sid_str] (0x0080): No [objectSIDString] attribute while id-mapping. [0][Success] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object dummy (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Processing user dummy (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Adding original memberOf attributes to [dummy]. (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Adding user principal [du...@mydomain.com] to attributes of [dummy]. (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_save_user] (0x0400): Storing info for user dummy (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object dummy (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_has_deref_support] (0x0400): The server supports deref method OpenLDAP (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=ipausers,cn=groups,cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=employee,cn=groups,cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][ipauniqueid=61d77496-1506-11e5-aae7-00505689b3d1,cn=hbac,dc=mydomain,dc=com]. (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_initgr_nested_search] (0x0040): Search for group ipauniqueid=61d77496-1506-11e5-aae7-00505689b3d1,cn=hbac,dc=mydomain,dc=com, returned 0 results. Skipping (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=sshldapusers,cn=groups,cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object ipausers (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object employee (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object sshldapusers (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_groups_next_base] (0x0400): Searching for groups with base [cn=accounts,dc=mydomain,dc=com] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(gidNumber=895400028)(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][cn=accounts,dc=mydomain,dc=com]. (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_groups_process] (0x0400): Search for groups, returned 1 results. (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_has_deref_support] (0x0400): The server supports deref method OpenLDAP (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_nested_group_recv] (0x0400): 0 users found in the hash table (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_nested_group_recv] (0x0400): 1 groups found in the hash table (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_attrs_get_sid_str] (0x0080): No [objectSIDString] attribute while id-mapping. [0][Success] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object dummy (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_save_group] (0x0400): Processing group dummy (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse domain SID from [(null)] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_process_ghost_members] (0x0400): The group has 0 members (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_process_ghost_members] (0x0400): Group has 0 members (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_save_group] (0x0400): Storing info for group dummy (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_get_primary_name] (0x0400): Processing object dummy (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_save_grpmem] (0x0400): Processing group dummy (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [sdap_save_grpmem] (0x0400): No members for group [dummy] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [be_req_set_domain] (0x0400): Changing request domain from [mydomain.com] to [mydomain.com] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Got request with the following data (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): command: PAM_CLOSE_SESSION (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): domain: mydomain.com (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): user: dummy (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): service: sshd (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): tty: ssh (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): ruser: (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): rhost: auth.mydomain.com (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): authtok type: 0 (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): priv: 1 (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): cli_pid: 27457 (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Sending result [0][mydomain.com] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [be_req_set_domain] (0x0400): Changing request domain from [mydomain.com] to [mydomain.com] (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Got request with the following data (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): command: PAM_SETCRED (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): domain: mydomain.com (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): user: dummy (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): service: sshd (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): tty: ssh (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): ruser: (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): rhost: auth.mydomain.com (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): authtok type: 0 (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): priv: 1 (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [pam_print_data] (0x0100): cli_pid: 27457 (Wed Jul 29 09:37:53 2015) [sssd[be[mydomain.com]]] [be_pam_handler] (0x0100): Sending result [0][mydomain.com]
-- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
