<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40"><head><meta http-equiv=Content-Type content="text/html; charset=us-ascii"><meta name=Generator content="Microsoft Word 15 (filtered medium)"><style><!--
/* Font Definitions */
@font-face
{font-family:"Cambria Math";
panose-1:2 4 5 3 5 4 6 3 2 4;}
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0cm;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri",sans-serif;}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:#0563C1;
text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
{mso-style-priority:99;
color:#954F72;
text-decoration:underline;}
span.EmailStyle17
{mso-style-type:personal-compose;
font-family:"Calibri",sans-serif;
color:windowtext;}
.MsoChpDefault
{mso-style-type:export-only;
font-family:"Calibri",sans-serif;}
@page WordSection1
{size:612.0pt 792.0pt;
margin:72.0pt 72.0pt 72.0pt 72.0pt;}
div.WordSection1
{page:WordSection1;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]--></head><body lang=EN-US link="#0563C1" vlink="#954F72"><div class=WordSection1><p class=MsoNormal>Hi,<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>I am having an issue with getting SSO to work when a standard user(UserRole) logs in to the UserPortal.<o:p></o:p></p><p class=MsoNormal>The user has permission to use only this VM, so after login the console is automatically opened for that VM.<o:p></o:p></p><p class=MsoNormal>Problem is that it doesn't login on the VM system with the provided credentials. Manual login at the console works without any issues. <o:p></o:p></p><p class=MsoNormal>HBAC-rule check on IPA shows access is granted. Client has SELINUX in permissive mode and a disabled firewalld. <o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>On the client side I do see some PAM related errors in the logs (see details below). Extensive Google search on error 17 "Failure setting user credentials" didn't show helpful information :-(<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>AFAIK this is did a pretty standard set-up, all working with RH-family products. I would expect others to encounter this issue as well. <o:p></o:p></p><p class=MsoNormal>If someone knows any solution or has some directions to fix this it would be greatly appreciated.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Thanks,<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Paul<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>------------------------------------------------------<o:p></o:p></p><p class=MsoNormal>System setup: I have 3 systems <o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>The connection between the Engine and IPA is working fine. (I can log in with IPA users etc.) Connection is made according to this document: https://access.redhat.com/documentation/en-US/Red_Hat_Enterprise_Virtualization/3.6/html-single/Administration_Guide/index.html#sect-Configuring_an_External_LDAP_Provider<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Configuration of the client is done according to this document: https://access.redhat.com/documentation/en-US/Red_Hat_Enterprise_Virtualization/3.6/html/Virtual_Machine_Management_Guide/chap-Additional_Configuration.html#sect-Configuring_Single_Sign-On_for_Virtual_Machines<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>--- Hosted Engine:<o:p></o:p></p><p class=MsoNormal>[root@engine ~]# cat /etc/redhat-release<o:p></o:p></p><p class=MsoNormal>CentOS Linux release 7.2.1511 (Core)<o:p></o:p></p><p class=MsoNormal>[root@engine ~]# uname -a<o:p></o:p></p><p class=MsoNormal>Linux engine.DOMAIN.COM 3.10.0-327.10.1.el7.x86_64 #1 SMP Tue Feb 16 17:03:50 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux<o:p></o:p></p><p class=MsoNormal>[root@engine ~]# rpm -qa | grep ovirt<o:p></o:p></p><p class=MsoNormal>ovirt-vmconsole-1.0.0-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-restapi-3.6.2.6-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-setup-lib-1.0.1-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-setup-plugin-ovirt-engine-common-3.6.3.4-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-setup-3.6.3.4-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-image-uploader-3.6.0-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-extension-aaa-jdbc-1.0.5-1.el7.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-host-deploy-1.4.1-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-extension-aaa-ldap-setup-1.1.2-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-wildfly-overlay-8.0.4-1.el7.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-wildfly-8.2.1-1.el7.x86_64<o:p></o:p></p><p class=MsoNormal>ovirt-vmconsole-proxy-1.0.0-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-tools-3.6.2.6-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-dbscripts-3.6.2.6-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-backend-3.6.2.6-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-3.6.2.6-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-extension-aaa-ldap-1.1.2-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-setup-base-3.6.3.4-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-setup-plugin-ovirt-engine-3.6.3.4-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-setup-plugin-websocket-proxy-3.6.3.4-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-vmconsole-proxy-helper-3.6.3.4-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-cli-3.6.2.0-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-host-deploy-java-1.4.1-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-userportal-3.6.2.6-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-webadmin-portal-3.6.2.6-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-guest-agent-common-1.0.11-1.el7.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-release36-003-1.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-iso-uploader-3.6.0-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-lib-3.6.3.4-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-sdk-python-3.6.3.0-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-setup-plugin-vmconsole-proxy-helper-3.6.3.4-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-websocket-proxy-3.6.3.4-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-log-collector-3.6.1-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-engine-extensions-api-impl-3.6.3.4-1.el7.centos.noarch<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>--- FreeIPA:<o:p></o:p></p><p class=MsoNormal>[root@ipa01 ~]# cat /etc/redhat-release<o:p></o:p></p><p class=MsoNormal>CentOS Linux release 7.2.1511 (Core) <o:p></o:p></p><p class=MsoNormal>[root@ipa01 ~]# uname -a<o:p></o:p></p><p class=MsoNormal>Linux ipa01.DOMAIN.COM 3.10.0-327.10.1.el7.x86_64 #1 SMP Tue Feb 16 17:03:50 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux<o:p></o:p></p><p class=MsoNormal>[root@ipa01 ~]# rpm -qa | grep ipa<o:p></o:p></p><p class=MsoNormal>ipa-python-4.2.0-15.el7_2.6.x86_64<o:p></o:p></p><p class=MsoNormal>ipa-client-4.2.0-15.el7_2.6.x86_64<o:p></o:p></p><p class=MsoNormal>python-libipa_hbac-1.13.0-40.el7_2.1.x86_64<o:p></o:p></p><p class=MsoNormal>python-iniparse-0.4-9.el7.noarch<o:p></o:p></p><p class=MsoNormal>libipa_hbac-1.13.0-40.el7_2.1.x86_64<o:p></o:p></p><p class=MsoNormal>sssd-ipa-1.13.0-40.el7_2.1.x86_64<o:p></o:p></p><p class=MsoNormal>ipa-admintools-4.2.0-15.el7_2.6.x86_64<o:p></o:p></p><p class=MsoNormal>ipa-server-4.2.0-15.el7_2.6.x86_64<o:p></o:p></p><p class=MsoNormal>ipa-server-dns-4.2.0-15.el7_2.6.x86_64<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>--- Client:<o:p></o:p></p><p class=MsoNormal>[root@test06 ~]# cat /etc/redhat-release<o:p></o:p></p><p class=MsoNormal>CentOS Linux release 7.2.1511 (Core) <o:p></o:p></p><p class=MsoNormal>[root@test06 ~]# uname -a<o:p></o:p></p><p class=MsoNormal>Linux test06.DOMAIN.COM 3.10.0-327.10.1.el7.x86_64 #1 SMP Tue Feb 16 17:03:50 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux<o:p></o:p></p><p class=MsoNormal>[root@test06 ~]# rpm -qa | grep ipa<o:p></o:p></p><p class=MsoNormal>python-libipa_hbac-1.13.0-40.el7_2.1.x86_64<o:p></o:p></p><p class=MsoNormal>python-iniparse-0.4-9.el7.noarch<o:p></o:p></p><p class=MsoNormal>sssd-ipa-1.13.0-40.el7_2.1.x86_64<o:p></o:p></p><p class=MsoNormal>ipa-client-4.2.0-15.0.1.el7.centos.6.x86_64<o:p></o:p></p><p class=MsoNormal>libipa_hbac-1.13.0-40.el7_2.1.x86_64<o:p></o:p></p><p class=MsoNormal>ipa-python-4.2.0-15.0.1.el7.centos.6.x86_64<o:p></o:p></p><p class=MsoNormal>device-mapper-multipath-0.4.9-85.el7.x86_64<o:p></o:p></p><p class=MsoNormal>device-mapper-multipath-libs-0.4.9-85.el7.x86_64<o:p></o:p></p><p class=MsoNormal>[root@test06 ~]# rpm -qa | grep guest-agent<o:p></o:p></p><p class=MsoNormal>qemu-guest-agent-2.3.0-4.el7.x86_64<o:p></o:p></p><p class=MsoNormal>ovirt-guest-agent-pam-module-1.0.11-1.el7.x86_64<o:p></o:p></p><p class=MsoNormal>ovirt-guest-agent-gdm-plugin-1.0.11-1.el7.noarch<o:p></o:p></p><p class=MsoNormal>ovirt-guest-agent-common-1.0.11-1.el7.noarch<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>---------------------------------------------------<o:p></o:p></p><p class=MsoNormal>Relevant logs:<o:p></o:p></p><p class=MsoNormal>--- Engine:<o:p></o:p></p><p class=MsoNormal>//var/log/ovirt-engine/engine<o:p></o:p></p><p class=MsoNormal>2016-03-17 15:22:10,516 INFO [org.ovirt.engine.core.bll.aaa.LoginUserCommand] (default task-22) [] Running command: LoginUserCommand internal: false.<o:p></o:p></p><p class=MsoNormal>2016-03-17 15:22:10,568 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-22) [] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User test6@DOMAIN logged in.<o:p></o:p></p><p class=MsoNormal>2016-03-17 15:22:13,795 WARN [org.ovirt.engine.core.dal.job.ExecutionMessageDirector] (default task-6) [7400ae46] The message key 'VmLogon' is missing from 'bundles/ExecutionMessages'<o:p></o:p></p><p class=MsoNormal>2016-03-17 15:22:13,839 INFO [org.ovirt.engine.core.bll.VmLogonCommand] (default task-6) [7400ae46] Running command: VmLogonCommand internal: false. Entities affected : ID: 64a84b40-6050-4a96-a59d-d557a317c38c Type: VMAction group CONNECT_TO_VM with role type USER<o:p></o:p></p><p class=MsoNormal>2016-03-17 15:22:13,842 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmLogonVDSCommand] (default task-6) [7400ae46] START, VmLogonVDSCommand(HostName = host01, VmLogonVDSCommandParameters:{runAsync='true', hostId='225157c0-224b-4aa6-9210-db4de7c7fc30', vmId='64a84b40-6050-4a96-a59d-d557a317c38c', domain='DOMAIN-authz', password='***', userName='test6@DOMAIN'}), log id: 2015a1e0<o:p></o:p></p><p class=MsoNormal>2016-03-17 15:22:14,848 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmLogonVDSCommand] (default task-6) [7400ae46] FINISH, VmLogonVDSCommand, log id: 2015a1e0<o:p></o:p></p><p class=MsoNormal>2016-03-17 15:22:15,317 INFO [org.ovirt.engine.core.bll.SetVmTicketCommand] (default task-18) [10dad788] Running command: SetVmTicketCommand internal: true. Entities affected : ID: 64a84b40-6050-4a96-a59d-d557a317c38c Type: VMAction group CONNECT_TO_VM with role type USER<o:p></o:p></p><p class=MsoNormal>2016-03-17 15:22:15,322 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (default task-18) [10dad788] START, SetVmTicketVDSCommand(HostName = host01, SetVmTicketVDSCommandParameters:{runAsync='true', hostId='225157c0-224b-4aa6-9210-db4de7c7fc30', vmId='64a84b40-6050-4a96-a59d-d557a317c38c', protocol='SPICE', ticket='rd8avqvdBnRl', validTime='120', userName='test6', userId='10b2da3e-6401-4a09-a330-c0780bc0faef', disconnectAction='LOCK_SCREEN'}), log id: 72efb73b<o:p></o:p></p><p class=MsoNormal>2016-03-17 15:22:16,340 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (default task-18) [10dad788] FINISH, SetVmTicketVDSCommand, log id: 72efb73b<o:p></o:p></p><p class=MsoNormal>2016-03-17 15:22:16,377 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-18) [10dad788] Correlation ID: 10dad788, Call Stack: null, Custom Event ID: -1, Message: User test6@DOMAIN initiated console session for VM test06<o:p></o:p></p><p class=MsoNormal>2016-03-17 15:22:19,418 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-53) [] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User test6@DOMAIN-authz is connected to VM test06.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>--- Client:<o:p></o:p></p><p class=MsoNormal>/var/log/ovirt-guest-agent/ovirt-guest-agent.log<o:p></o:p></p><p class=MsoNormal>MainThread::INFO::2016-03-17 15:20:58,145::ovirt-guest-agent::57::root::Starting oVirt guest agent<o:p></o:p></p><p class=MsoNormal>CredServer::INFO::2016-03-17 15:20:58,214::CredServer::257::root::CredServer is running...<o:p></o:p></p><p class=MsoNormal>Dummy-1::INFO::2016-03-17 15:20:58,216::OVirtAgentLogic::294::root::Received an external command: lock-screen...<o:p></o:p></p><p class=MsoNormal>Dummy-1::INFO::2016-03-17 15:22:13,104::OVirtAgentLogic::294::root::Received an external command: login...<o:p></o:p></p><p class=MsoNormal>Dummy-1::INFO::2016-03-17 15:22:13,104::CredServer::207::root::The following users are allowed to connect: [0]<o:p></o:p></p><p class=MsoNormal>Dummy-1::INFO::2016-03-17 15:22:13,104::CredServer::273::root::Opening credentials channel...<o:p></o:p></p><p class=MsoNormal>Dummy-1::INFO::2016-03-17 15:22:13,105::CredServer::132::root::Emitting user authenticated signal (651416).<o:p></o:p></p><p class=MsoNormal>CredChannel::INFO::2016-03-17 15:22:13,188::CredServer::225::root::Incomming connection from user: 0 process: 2570<o:p></o:p></p><p class=MsoNormal>CredChannel::INFO::2016-03-17 15:22:13,188::CredServer::232::root::Sending user's credential (token: 651416)<o:p></o:p></p><p class=MsoNormal>Dummy-1::INFO::2016-03-17 15:22:13,189::CredServer::277::root::Credentials channel was closed.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>/var/log/secure<o:p></o:p></p><p class=MsoNormal>Mar 17 15:21:07 test06 gdm-launch-environment]: pam_unix(gdm-launch-environment:session): session opened for user gdm by (uid=0)<o:p></o:p></p><p class=MsoNormal>Mar 17 15:21:10 test06 polkitd[749]: Registered Authentication Agent for unix-session:c1 (system bus name :1.34 [gnome-shell --mode=gdm], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)<o:p></o:p></p><p class=MsoNormal>Mar 17 15:22:13 test06 gdm-ovirtcred]: pam_sss(gdm-ovirtcred:auth): authentication failure; logname= uid=0 euid=0 tty= ruser= rhost= user=test6<o:p></o:p></p><p class=MsoNormal><b><span style='color:red'>Mar 17 15:22:13 test06 gdm-ovirtcred]: pam_sss(gdm-ovirtcred:auth): received for user test6: 17 (Failure setting user credentials)<o:p></o:p></span></b></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><span lang=NL>/var/log/sssd/krb5_child.log (debug-level 10)<o:p></o:p></span></p><p class=MsoNormal><b><span style='color:red'>(Thu Mar 17 15:22:13 2016) [[sssd[krb5_child[2575]]]] [get_and_save_tgt] (0x0020): 1234: [-1765328360][Preauthentication failed]<o:p></o:p></span></b></p><p class=MsoNormal><b><span style='color:red'>(Thu Mar 17 15:22:13 2016) [[sssd[krb5_child[2575]]]] [map_krb5_error] (0x0020): 1303: [-1765328360][Preauthentication failed]<o:p></o:p></span></b></p><p class=MsoNormal><b><span style='color:red'>(Thu Mar 17 15:22:13 2016) [[sssd[krb5_child[2575]]]] [k5c_send_data] (0x0200): Received error code 1432158215<o:p></o:p></span></b></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [[sssd[krb5_child[2575]]]] [pack_response_packet] (0x2000): response packet size: [4]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [[sssd[krb5_child[2575]]]] [k5c_send_data] (0x4000): Response sent.<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [[sssd[krb5_child[2575]]]] [main] (0x0400): krb5_child completed successfully<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>/var/log/sssd/sssd_DOMAIN.COM.log (debug-level 10)<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [be_pam_handler] (0x0100): Got request with the following data<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [pam_print_data] (0x0100): domain: DOMAIN.COM<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [pam_print_data] (0x0100): user: test6<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [pam_print_data] (0x0100): service: gdm-ovirtcred<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [pam_print_data] (0x0100): tty:<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [pam_print_data] (0x0100): ruser:<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [pam_print_data] (0x0100): rhost:<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [pam_print_data] (0x0100): authtok type: 1<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [pam_print_data] (0x0100): newauthtok type: 0<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [pam_print_data] (0x0100): priv: 1<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [pam_print_data] (0x0100): cli_pid: 2570<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [pam_print_data] (0x0100): logon name: not set<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [krb5_auth_queue_send] (0x1000): Wait queue of user [test6] is empty, running request [0x7fe30df03cc0] immediately.<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [krb5_setup] (0x4000): No mapping for: test6<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fe30df07120<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fe30df16590<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [ldb] (0x4000): Running timer event 0x7fe30df07120 "ltdb_callback"<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [ldb] (0x4000): Destroying timer event 0x7fe30df16590 "ltdb_timeout"<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [ldb] (0x4000): Ending timer event 0x7fe30df07120 "ltdb_callback"<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [get_server_status] (0x1000): Status of server 'ipa01.DOMAIN.COM' is 'working'<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [get_port_status] (0x1000): Port status of port 389 for server 'ipa01.DOMAIN.COM' is 'working'<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [get_server_status] (0x1000): Status of server 'ipa01.DOMAIN.COM' is 'working'<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [be_resolve_server_process] (0x1000): Saving the first resolved server<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [be_resolve_server_process] (0x0200): Found address for server ipa01.DOMAIN.COM: [10.0.1.21] TTL 1200<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://ipa01.DOMAIN.COM'<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sss_krb5_realm_has_proxy] (0x0040): profile_get_values failed.<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [2575]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [child_handler_setup] (0x2000): Signal handler set up for pid [2575]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [write_pipe_handler] (0x0400): All data has been sent!<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [child_sig_handler] (0x1000): Waiting for child [2575].<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [child_sig_handler] (0x0100): child [2575] finished successfully.<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [read_pipe_handler] (0x0400): EOF received, client finished<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [check_wait_queue] (0x1000): Wait queue for user [test6] is empty.<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [krb5_auth_queue_done] (0x1000): krb5_auth_queue request [0x7fe30df03cc0] done.<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_print_server] (0x2000): Searching 10.0.1.21<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(cn=ipaConfig)(objectClass=ipaGuiConfig))][cn=etc,dc=DOMAIN,dc=com].<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaMigrationEnabled]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaSELinuxUserMapDefault]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaSELinuxUserMapOrder]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 122<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_op_add] (0x2000): New operation 122 timeout 60<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_process_result] (0x2000): Trace: sh[0x7fe30deef090], connected[1], ops[0x7fe30df094a0], ldap[0x7fe30def2920]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_parse_entry] (0x1000): OriginalDN: [cn=ipaConfig,cn=etc,dc=DOMAIN,dc=com].<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_parse_range] (0x2000): No sub-attributes for [ipaMigrationEnabled]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_parse_range] (0x2000): No sub-attributes for [ipaSELinuxUserMapDefault]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_parse_range] (0x2000): No sub-attributes for [ipaSELinuxUserMapOrder]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_process_result] (0x2000): Trace: sh[0x7fe30deef090], connected[1], ops[0x7fe30df094a0], ldap[0x7fe30def2920]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set<o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_op_destructor] (0x2000): Operation 122 finished <o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_id_op_destroy] (0x4000): releasing operation connection <o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [ipa_get_migration_flag_done] (0x0100): Password migration is not enabled. <o:p></o:p></p><p class=MsoNormal><b><span style='color:red'>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 17, <NULL>) [Success (Failure setting user credentials)] <o:p></o:p></span></b></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [be_pam_handler_callback] (0x0100): Sending result [17][DOMAIN.COM] <o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [be_pam_handler_callback] (0x0100): Sent result [17][DOMAIN.COM] <o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_process_result] (0x2000): Trace: sh[0x7fe30deef090], connected[1], ops[(nil)], ldap[0x7fe30def2920] <o:p></o:p></p><p class=MsoNormal>(Thu Mar 17 15:22:13 2016) [sssd[be[DOMAIN.COM]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal> <o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><o:p> </o:p></p></div></body></html>