[Freeipa-users] Some computers cannot get Some users logged in.

Thu May 29 18:20:37 UTC 2014

Hi,
Having a particularly weird problem. We have moved from AD to freeIPA
recently and while there have been some bumps, most of the CentOS 6.2 boxes
make the transition successfully. Some background.

The Linux boxes were joined to AD on Windows 2008R2 using samba/winbind.
When we moved from AD, boxes were not "removed" from AD, just disabled on
the server side. We scripted the necessary bits since we were moving to a
new subnet as well. The script runs "ipa-client-install -p admin --password
PASSWORD --enable-dns-updates -U"

The machines were joined successfully to freeIPA and then added to
allow_all_hosts Host Group.

On a workstation that was migrated, all users can successfully log in.
On a fresh install of CentOS6.2, only myself (admin_user) and a newly
created user (foo) can successfully log in.

On this fresh install, 'david' is blocked but new user 'foo' is allowed.

May 29 09:20:29 embassy419 polkitd(authority=local): Registered
Authentication Agent for session /org/freedesktop/ConsoleKit/Session1
(system bus name :1.26 [/usr/libexec/polkit-gnome-authentication-agent-1],
object path /org/gnome/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
May 29 09:20:46 embassy419 pam: gdm-password[2910]:
pam_unix(gdm-password:auth): authentication failure; logname= uid=0 euid=0
tty=:0 ruser= rhost=  user=david
May 29 09:20:47 embassy419 pam: gdm-password[2910]:
pam_sss(gdm-password:auth): system info: [Preauthentication failed]
May 29 09:20:47 embassy419 pam: gdm-password[2910]:
pam_sss(gdm-password:auth): authentication failure; logname= uid=0 euid=0
tty=:0 ruser= rhost= user=david
May 29 09:20:47 embassy419 pam: gdm-password[2910]:
pam_sss(gdm-password:auth): received for user david: 17 (Failure setting
user credentials)
May 29 10:44:06 embassy419 polkitd(authority=local): Registered
Authentication Agent for session /org/freedesktop/ConsoleKit/Session3
(system bus name :1.88 [/usr/libexec/polkit-gnome-authentication-agent-1],
object path /org/gnome/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
May 29 10:44:13 embassy419 pam: gdm-password[3956]:
pam_unix(gdm-password:auth): authentication failure; logname= uid=0 euid=0
tty=:1 ruser= rhost=  user=foo
May 29 10:44:14 embassy419 pam: gdm-password[3956]:
pam_sss(gdm-password:auth): authentication success; logname= uid=0 euid=0
tty=:1 ruser= rhost= user=foo
May 29 10:44:14 embassy419 pam: gdm-password[3956]:
pam_unix(gdm-password:session): session opened for user foo by (uid=0)
May 29 10:44:15 embassy419 polkitd(authority=local): Unregistered
Authentication Agent for session /org/freedesktop/ConsoleKit/Session3
(system bus name :1.88, object path
/org/gnome/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
(disconnected from bus)

But on this machine that was migrated.
pam: gdm-password[14145]: pam_unix(gdm-password:auth): authentication
failure; logname= uid=0 euid=0 tty=:1 ruser= rhost=  user=david
May 29 10:42:08 Embassy426 pam: gdm-password[14145]:
pam_sss(gdm-password:auth): system info: [Preauthentication failed]
May 29 10:42:08 Embassy426 pam: gdm-password[14145]:
pam_sss(gdm-password:auth): authentication failure; logname= uid=0 euid=0
tty=:1 ruser= rhost= user=david
May 29 10:42:08 Embassy426 pam: gdm-password[14145]:
pam_sss(gdm-password:auth): received for user david: 17 (Failure setting
user credentials)
May 29 10:42:08 Embassy426 pam: gdm-password[14145]:
pam_winbind(gdm-password:auth): getting password (0x00000010)
May 29 10:42:08 Embassy426 pam: gdm-password[14145]:
pam_winbind(gdm-password:auth): pam_get_item returned a password
May 29 10:42:09 Embassy426 pam: gdm-password[14145]:
pam_winbind(gdm-password:auth): user 'david' granted access
May 29 10:42:09 Embassy426 pam: gdm-password[14145]:
pam_winbind(gdm-password:account): valid_user: wbcGetpwnam gave
WBC_ERR_DOMAIN_NOT_FOUND
May 29 10:42:10 Embassy426 pam: gdm-password[14145]:
pam_unix(gdm-password:session): session opened for user david by (uid=0)
May 29 10:42:10 Embassy426 polkitd(authority=local): Unregistered
Authentication Agent for session /org/freedesktop/ConsoleKit/Session3
(system bus name :1.85, object path
/org/gnome/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
(disconnected from bus)
May 29 10:42:11 Embassy426 polkitd(authority=local): Registered
Authentication Agent for session /org/freedesktop/ConsoleKit/Session4
(system bus name :1.105 [/usr/libexec/polkit-gnome-authentication-agent-1],
object path /org/gnome/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
May 29 10:42:56 Embassy426 pam: gdm-password[15052]:
pam_unix(gdm-password:auth): authentication failure; logname= uid=0 euid=0
tty=:3 ruser= rhost=  user=foo
May 29 10:42:57 Embassy426 pam: gdm-password[15052]:
pam_sss(gdm-password:auth): authentication success; logname= uid=0 euid=0
tty=:3 ruser= rhost= user=foo
May 29 10:42:57 Embassy426 pam: gdm-password[15052]:
pam_winbind(gdm-password:account): valid_user: wbcGetpwnam gave
WBC_ERR_DOMAIN_NOT_FOUND
May 29 10:42:59 Embassy426 pam: gdm-password[15052]:
pam_unix(gdm-password:session): session opened for user foo by (uid=0)
May 29 10:42:59 Embassy426 polkitd(authority=local): Unregistered
Authentication Agent for session /org/freedesktop/ConsoleKit/Session7
(system bus name :1.160, object path
/org/gnome/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
(disconnected from bus)
May 29 10:42:59 Embassy426 polkitd(authority=local): Registered
Authentication Agent for session /org/freedesktop/ConsoleKit/Session8
(system bus name :1.175 [/usr/libexec/polkit-gnome-authentication-agent-1],
object path /org/gnome/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)

The dirserv says this about david from the broken PC

[29/May/2014:09:20:46 -0700] conn=8 op=1526 SRCH base="dc=embassy,dc=vfx"
scope=2
filter="(&(|(objectClass=krbprincipalaux)(objectClass=krbprincipal)(objectClass=ipakrbprincip
al))(|(ipaKrbPrincipalAlias=david at EMBASSY.VFX
)(krbPrincipalName=david at EMBASSY.VFX)))" attrs="krbPrincipalName
krbCanonicalName ipaKrbPrincipalAlias krbUPEnabled krbPrincipalKe
y krbTicketPolicyReference krbPrincipalExpiration krbPasswordExpiration
krbPwdPolicyReference krbPrincipalType krbPwdHistory krbLastPwdChange
krbPrincipalAliases krbLastSucces
sfulAuth krbLastFailedAuth krbLoginFailedCount krbExtraData
krbLastAdminUnlock krbObjectReferences krbTicketFlags krbMaxTicketLife
krbMaxRenewableAge nsAccountLock passwordHis
tory objectClass"
[29/May/2014:09:20:46 -0700] conn=8 op=1526 RESULT err=0 tag=101 nentries=1
etime=0
[29/May/2014:09:20:46 -0700] conn=8 op=1527 SRCH
base="cn=EMBASSY.VFX,cn=kerberos,dc=embassy,dc=vfx" scope=0
filter="(objectClass=krbticketpolicyaux)" attrs="krbMaxTicketLife
krbMaxRenewableAge krbTicketFlags"
[29/May/2014:09:20:46 -0700] conn=8 op=1527 RESULT err=0 tag=101 nentries=1
etime=0
[29/May/2014:09:20:46 -0700] conn=8 op=1528 SRCH base="dc=embassy,dc=vfx"
scope=2
filter="(&(|(objectClass=krbprincipalaux)(objectClass=krbprincipal)(objectClass=ipakrbprincip
al))(|(ipaKrbPrincipalAlias=krbtgt/EMBASSY.VFX at EMBASSY.VFX
)(krbPrincipalName=krbtgt/EMBASSY.VFX at EMBASSY.VFX)))"
attrs="krbPrincipalName krbCanonicalName ipaKrbPrincipalAlias k
rbUPEnabled krbPrincipalKey krbTicketPolicyReference krbPrincipalExpiration
krbPasswordExpiration krbPwdPolicyReference krbPrincipalType krbPwdHistory
krbLastPwdChange krbPrin
cipalAliases krbLastSuccessfulAuth krbLastFailedAuth krbLoginFailedCount
krbExtraData krbLastAdminUnlock krbObjectReferences krbTicketFlags
krbMaxTicketLife krbMaxRenewableAge
 nsAccountLock passwordHistory objectClass"
[29/May/2014:09:20:46 -0700] conn=8 op=1528 RESULT err=0 tag=101 nentries=1
etime=0
[29/May/2014:09:20:46 -0700] conn=8 op=1529 SRCH
base="cn=global_policy,cn=EMBASSY.VFX,cn=kerberos,dc=embassy,dc=vfx"
scope=0 filter="(objectClass=*)" attrs="krbMaxPwdLife krb
MinPwdLife krbPwdMinDiffChars krbPwdMinLength krbPwdHistoryLength
krbPwdMaxFailure krbPwdFailureCountInterval krbPwdLockoutDuration"
[29/May/2014:09:20:46 -0700] conn=8 op=1529 RESULT err=0 tag=101 nentries=1
etime=0
[29/May/2014:09:20:46 -0700] conn=8 op=1530 MOD
dn="uid=david,cn=users,cn=accounts,dc=embassy,dc=vfx"
[29/May/2014:09:20:46 -0700] conn=8 op=1530 RESULT err=0 tag=103 nentries=0
etime=0 csn=53875e73000000030000

>From a Migrated working machine (more debugging turned on)
[29/May/2014:10:42:04 -0700] conn=72 op=14 SRCH
base="cn=accounts,dc=embassy,dc=vfx" scope=2
filter="(&(uid=david)(objectClass=posixAccount))" attrs="objectClass uid
userPassword uidNumber gidNumber gecos homeDirectory loginShell
krbPrincipalName cn memberOf nsUniqueId modifyTimestamp entryusn
shadowLastChange shadowMin shadowMax shadowWarning shadowInactive
shadowExpire shadowFlag krbLastPwdChange krbPasswordExpiration pwdattribute
authorizedService accountexpires useraccountcontrol nsAccountLock host
logindisabled loginexpirationtime loginallowedtimemap ipaSshPubKey"
[29/May/2014:10:42:04 -0700] conn=72 op=14 RESULT err=0 tag=101 nentries=1
etime=0
[29/May/2014:10:42:08 -0700] conn=72 op=15 SRCH
base="cn=accounts,dc=embassy,dc=vfx" scope=2
filter="(&(uid=david)(objectClass=posixAccount))" attrs="objectClass uid
userPassword uidNumber gidNumber gecos homeDirectory loginShell
krbPrincipalName cn memberOf nsUniqueId modifyTimestamp entryusn
shadowLastChange shadowMin shadowMax shadowWarning shadowInactive
shadowExpire shadowFlag krbLastPwdChange krbPasswordExpiration pwdattribute
authorizedService accountexpires useraccountcontrol nsAccountLock host
logindisabled loginexpirationtime loginallowedtimemap ipaSshPubKey"
[29/May/2014:10:42:08 -0700] conn=72 op=15 RESULT err=0 tag=101 nentries=1
etime=0
[29/May/2014:10:42:08 -0700] conn=72 op=16 SRCH
base="cn=ipausers,cn=groups,cn=accounts,dc=embassy,dc=vfx" scope=0
filter="(&(objectClass=posixGroup)(cn=*))" attrs="objectClass cn
userPassword gidNumber member nsUniqueId modifyTimestamp entryusn"
[29/May/2014:10:42:08 -0700] conn=72 op=16 RESULT err=0 tag=101 nentries=0
etime=0
[29/May/2014:10:42:08 -0700] conn=72 op=17 SRCH
base="cn=emb_users,cn=groups,cn=accounts,dc=embassy,dc=vfx" scope=0
filter="(&(objectClass=posixGroup)(cn=*))" attrs="objectClass cn
userPassword gidNumber member nsUniqueId modifyTimestamp entryusn"
[29/May/2014:10:42:08 -0700] conn=72 op=17 RESULT err=0 tag=101 nentries=1
etime=0
[29/May/2014:10:42:08 -0700] conn=72 op=18 SRCH
base="cn=etc,dc=embassy,dc=vfx" scope=2
filter="(&(cn=ipaConfig)(objectClass=ipaGuiConfig))"
attrs="ipaMigrationEnabled ipaSELinuxUserMapDefault ipaSELinuxUserMapOrder"
[29/May/2014:10:42:08 -0700] conn=72 op=18 RESULT err=0 tag=101 nentries=1
etime=0
[29/May/2014:10:42:08 -0700] conn=72 op=19 SRCH
base="cn=accounts,dc=embassy,dc=vfx" scope=2
filter="(&(objectClass=ipaHost)(fqdn=embassy426.embassy.vfx))"
attrs="objectClass cn fqdn serverHostName memberOf ipaSshPubKey ipaUniqueID"
[29/May/2014:10:42:08 -0700] conn=72 op=19 RESULT err=0 tag=101 nentries=1
etime=0 notes=P
[29/May/2014:10:42:08 -0700] conn=72 op=20 SRCH
base="fqdn=embassy426.embassy.vfx,cn=computers,cn=accounts,dc=embassy,dc=vfx"
scope=0 filter="(objectClass=*)" attrs="objectClass cn memberOf ipaUniqueID"
[29/May/2014:10:42:08 -0700] conn=72 op=20 RESULT err=0 tag=101 nentries=1
etime=0 notes=P
[29/May/2014:10:42:08 -0700] conn=72 op=21 SRCH
base="cn=hbac,dc=embassy,dc=vfx" scope=2
filter="(objectClass=ipaHBACService)" attrs="objectClass cn ipaUniqueID
member memberOf"
[29/May/2014:10:42:08 -0700] conn=72 op=21 RESULT err=0 tag=101 nentries=15
etime=0 notes=P
[29/May/2014:10:42:08 -0700] conn=72 op=22 SRCH
base="cn=hbac,dc=embassy,dc=vfx" scope=2
filter="(objectClass=ipaHBACServiceGroup)" attrs="objectClass cn
ipaUniqueID member memberOf"
[29/May/2014:10:42:08 -0700] conn=72 op=22 RESULT err=0 tag=101 nentries=2
etime=0 notes=P
[29/May/2014:10:42:08 -0700] conn=72 op=23 SRCH
base="cn=hbac,dc=embassy,dc=vfx" scope=2
filter="(&(objectClass=ipaHBACRule)(ipaEnabledFlag=TRUE)(|(hostCategory=all)(memberHost=fqdn=embassy426.embassy.vfx,cn=computers,cn=accounts,dc=embassy,dc=vfx)(memberHost=cn=allow_all_hosts,cn=hostgroups,cn=accounts,dc=embassy,dc=vfx)(memberHost=cn=allow_all_hosts,cn=ng,cn=alt,dc=embassy,dc=vfx)(memberHost=ipauniqueid=6e07ee2e-d495-11e3-9c3b-00304881a4bc,cn=hbac,dc=embassy,dc=vfx)))"
attrs="objectClass cn ipaUniqueID ipaEnabledFlag accessRuleType memberUser
userCategory memberService serviceCategory sourceHost sourceHostCategory
externalHost memberHost hostCategory"
[29/May/2014:10:42:08 -0700] conn=72 op=23 RESULT err=0 tag=101 nentries=1
etime=0 notes=P
[29/May/2014:10:42:08 -0700] conn=72 op=24 SRCH
base="cn=etc,dc=embassy,dc=vfx" scope=2
filter="(&(cn=ipaConfig)(objectClass=ipaGuiConfig))"
attrs="ipaMigrationEnabled ipaSELinuxUserMapDefault ipaSELinuxUserMapOrder"
[29/May/2014:10:42:08 -0700] conn=72 op=24 RESULT err=0 tag=101 nentries=1
etime=0
[29/May/2014:10:42:08 -0700] conn=72 op=25 SRCH
base="cn=selinux,dc=embassy,dc=vfx" scope=2
filter="(&(objectClass=ipaselinuxusermap)(ipaEnabledFlag=TRUE))"
attrs="objectClass cn memberUser memberHost seeAlso ipaSELinuxUser
ipaEnabledFlag userCategory hostCategory ipaUniqueID"
[29/May/2014:10:42:08 -0700] conn=72 op=25 RESULT err=0 tag=101 nentries=0
etime=0 notes=P
[29/May/2014:10:42:09 -0700] conn=72 op=26 SRCH
base="cn=accounts,dc=embassy,dc=vfx" scope=2
filter="(&(cn=pulse-rt)(objectClass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))"
attrs="objectClass cn userPassword gidNumber member nsUniqueId
modifyTimestamp entryusn"
[29/May/2014:10:42:09 -0700] conn=72 op=26 RESULT err=0 tag=101 nentries=0
etime=1
[29/May/2014:10:42:09 -0700] conn=72 op=27 SRCH
base="cn=accounts,dc=embassy,dc=vfx" scope=2
filter="(&(gidNumber=16777729)(objectClass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))"
attrs="objectClass cn userPassword gidNumber member nsUniqueId
modifyTimestamp entryusn"
[29/May/2014:10:42:09 -0700] conn=72 op=27 RESULT err=0 tag=101 nentries=1
etime=0
[29/May/2014:10:42:09 -0700] conn=72 op=28 SRCH
base="cn=emb_users,cn=groups,cn=accounts,dc=embassy,dc=vfx" scope=0
filter="(objectClass=*)" attrs="objectClass cn userPassword gidNumber
member nsUniqueId modifyTimestamp entryusn uid"
[29/May/2014:10:42:09 -0700] conn=72 op=28 RESULT err=0 tag=101 nentries=1
etime=0 notes=P

I can see that winbind is somehow involved but
1) Both machines are disabled in AD
2) The new user 'foo' is not in AD but can still log in

I have tried copying over the pam.d folder from a working PC with no luck
as well.
The weird part is the migrated machine behaves "better" than the clean
install.....
Anything leap out? I can send more info if required.

Thanks
Scott A

-- 
Scott Allen
Head of IT
The Embassy Visual Effects Inc.
4th Floor - 177 W 7th Avenue
Vancouver, B.C.
V5Y 1L8
604.696.6862 ext 241
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20140529/c8e5808f/attachment.htm>