Bug 803054
| Summary: | ipa commands after upgrade return Insufficient access: KDC returned NOT_ALLOWED_TO_DELEGATE | ||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | Red Hat Enterprise Linux 6 | Reporter: | Scott Poore <spoore> | ||||||||
| Component: | ipa | Assignee: | Rob Crittenden <rcritten> | ||||||||
| Status: | CLOSED WORKSFORME | QA Contact: | IDM QE LIST <seceng-idm-qe-list> | ||||||||
| Severity: | unspecified | Docs Contact: | |||||||||
| Priority: | unspecified | ||||||||||
| Version: | 6.3 | CC: | jgalipea, mkosek, nkinder, rmeggins | ||||||||
| Target Milestone: | rc | ||||||||||
| Target Release: | --- | ||||||||||
| Hardware: | Unspecified | ||||||||||
| OS: | Unspecified | ||||||||||
| Whiteboard: | |||||||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||||||
| Doc Text: | Story Points: | --- | |||||||||
| Clone Of: | Environment: | ||||||||||
| Last Closed: | 2012-04-09 18:37:55 UTC | Type: | --- | ||||||||
| Regression: | --- | Mount Type: | --- | ||||||||
| Documentation: | --- | CRM: | |||||||||
| Verified Versions: | Category: | --- | |||||||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||||||
| Embargoed: | |||||||||||
| Attachments: |
|
||||||||||
Can you check 389-ds error and logs? The Add failures mean that the delegation entries were not added and logs may tell the tale. Running the updater again may help isolate the access log entries, and can you add the -d flag to get more verbose output from it (it still won't log the failure reason but it will at least show if it would have tried the right thing)? Should I attach the full logs from /var/log/dirsrv/slapd-<domain>/ for access and errors? Or is what I list below what you're looking for? I think I see some errors in the access log but, I'm not quite sure what I'm looking at there. Running the updater again: # ipa-ldap-updater -d --ldapi /usr/share/ipa/updates/30-s4u2proxy.update ipa : DEBUG importing all plugin modules in '/usr/lib/python2.6/site-packages/ipalib/plugins'... ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/aci.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/automember.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/automount.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/baseldap.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/batch.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/cert.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/config.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/delegation.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/dns.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/group.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/hbacrule.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/hbacsvc.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/hbacsvcgroup.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/hbactest.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/host.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/hostgroup.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/internal.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/kerberos.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/krbtpolicy.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/migration.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/misc.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/netgroup.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/passwd.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/permission.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/ping.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/privilege.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/pwpolicy.py' ipa : DEBUG args=klist -V ipa : DEBUG stdout=Kerberos 5 version 1.9 ipa : DEBUG stderr= ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/role.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/selfservice.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/selinuxusermap.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/service.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/sudocmd.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/sudocmdgroup.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/sudorule.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/user.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/virtual.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipalib/plugins/xmlclient.py' ipa : DEBUG importing all plugin modules in '/usr/lib/python2.6/site-packages/ipaserver/plugins'... ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipaserver/plugins/dogtag.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipaserver/plugins/join.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipaserver/plugins/ldap2.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipaserver/plugins/rabase.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipaserver/plugins/selfsign.py' ipa : DEBUG skipping plugin module ipaserver.plugins.selfsign: selfsign is not selected as RA plugin, it is dogtag ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipaserver/plugins/xmlserver.py' ipa : DEBUG importing all plugin modules in '/usr/lib/python2.6/site-packages/ipaserver/install/plugins'... ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipaserver/install/plugins/baseupdate.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipaserver/install/plugins/dns.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipaserver/install/plugins/fix_replica_memberof.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipaserver/install/plugins/rename_managed.py' ipa : DEBUG importing plugin module '/usr/lib/python2.6/site-packages/ipaserver/install/plugins/updateclient.py' ipa.ipalib.session.SessionAuthManager: DEBUG SessionAuthManager.register: name=jsonserver_session ipa.ipaserver.rpcserver.wsgi_dispatch: DEBUG Mounting ipaserver.rpcserver.xmlserver() at '/xml' ipa.ipaserver.rpcserver.wsgi_dispatch: DEBUG Mounting ipaserver.rpcserver.jsonserver_kerb() at '/json' ipa.ipaserver.rpcserver.wsgi_dispatch: DEBUG Mounting ipaserver.rpcserver.jsonserver_session() at '/session/json' ipa.ipaserver.rpcserver.jsonserver_session: DEBUG session_auth_duration: 0:20:00 ipa.ipaserver.rpcserver.wsgi_dispatch: DEBUG Mounting ipaserver.rpcserver.login_password() at '/session/login_password' ipa.ipaserver.rpcserver.login_password: DEBUG session_auth_duration: 0:20:00 ipa.ipaserver.rpcserver.wsgi_dispatch: DEBUG Mounting ipaserver.rpcserver.login_kerberos() at '/session/login_kerberos' ipa.ipaserver.rpcserver.login_kerberos: DEBUG session_auth_duration: 0:20:00 ipa : INFO Parsing file /usr/share/ipa/updates/30-s4u2proxy.update ipa : INFO Updating existing entry: cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG --------------------------------------------- ipa : DEBUG dn: cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG objectclass: ipa : DEBUG nsContainer ipa : DEBUG top ipa : DEBUG cn: s4u2proxy ipa : DEBUG --------------------------------------------- ipa : DEBUG Final value ipa : DEBUG dn: cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG objectclass: ipa : DEBUG nsContainer ipa : DEBUG top ipa : DEBUG cn: s4u2proxy ipa : DEBUG [] ipa : DEBUG Live 1, updated 0 ipa : INFO Done ipa : INFO New entry: cn=ipa-http-delegation,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG --------------------------------------------- ipa : DEBUG dn: cn=ipa-http-delegation,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG objectclass: ipa : DEBUG ipaKrb5DelegationACL ipa : DEBUG groupOfPrincipals ipa : DEBUG top ipa : DEBUG ipaallowedtarget: cn=ipa-ldap-delegation-targets,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG memberprincipal: HTTP/ibm-ls22-05.testrelm.com ipa : DEBUG cn: ipa-http-delegation ipa : DEBUG add: 'HTTP/ibm-ls22-05.testrelm.com' to memberPrincipal, current value ['HTTP/ibm-ls22-05.testrelm.com'] ipa : DEBUG add: updated value [u'HTTP/ibm-ls22-05.testrelm.com'] ipa : DEBUG --------------------------------------------- ipa : DEBUG dn: cn=ipa-http-delegation,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG objectclass: ipa : DEBUG ipaKrb5DelegationACL ipa : DEBUG groupOfPrincipals ipa : DEBUG top ipa : DEBUG ipaallowedtarget: cn=ipa-ldap-delegation-targets,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG memberPrincipal: ipa : DEBUG HTTP/ibm-ls22-05.testrelm.com ipa : DEBUG cn: ipa-http-delegation ipa : DEBUG --------------------------------------------- ipa : DEBUG Final value ipa : DEBUG dn: cn=ipa-http-delegation,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG objectclass: ipa : DEBUG ipaKrb5DelegationACL ipa : DEBUG groupOfPrincipals ipa : DEBUG top ipa : DEBUG ipaallowedtarget: cn=ipa-ldap-delegation-targets,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG memberPrincipal: ipa : DEBUG HTTP/ibm-ls22-05.testrelm.com ipa : DEBUG cn: ipa-http-delegation ipa : ERROR Add failure 'NoneType' object is not callable ipa : INFO New entry: cn=ipa-ldap-delegation-targets,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG --------------------------------------------- ipa : DEBUG dn: cn=ipa-ldap-delegation-targets,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG objectclass: ipa : DEBUG groupOfPrincipals ipa : DEBUG top ipa : DEBUG memberprincipal: ldap/ibm-ls22-05.testrelm.com ipa : DEBUG cn: ipa-ldap-delegation-targets ipa : DEBUG add: 'ldap/ibm-ls22-05.testrelm.com' to memberPrincipal, current value ['ldap/ibm-ls22-05.testrelm.com'] ipa : DEBUG add: updated value [u'ldap/ibm-ls22-05.testrelm.com'] ipa : DEBUG --------------------------------------------- ipa : DEBUG dn: cn=ipa-ldap-delegation-targets,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG objectclass: ipa : DEBUG groupOfPrincipals ipa : DEBUG top ipa : DEBUG memberPrincipal: ipa : DEBUG ldap/ibm-ls22-05.testrelm.com ipa : DEBUG cn: ipa-ldap-delegation-targets ipa : DEBUG --------------------------------------------- ipa : DEBUG Final value ipa : DEBUG dn: cn=ipa-ldap-delegation-targets,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : DEBUG objectclass: ipa : DEBUG groupOfPrincipals ipa : DEBUG top ipa : DEBUG memberPrincipal: ipa : DEBUG ldap/ibm-ls22-05.testrelm.com ipa : DEBUG cn: ipa-ldap-delegation-targets ipa : ERROR Add failure 'NoneType' object is not callable ipa : INFO Update complete From /var/log/dirsrv/slapd-TESTRELM-COM/errors: [13/Mar/2012:19:17:15 -0400] - Entry "cn=ipa-http-delegation,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com" has unknown object class "ipaKrb5DelegationACL" [13/Mar/2012:19:17:15 -0400] - Entry "cn=ipa-http-delegation,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com" has unknown object class "groupOfPrincipals" [13/Mar/2012:19:17:15 -0400] - Entry "cn=ipa-ldap-delegation-targets,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com" has unknown object class "groupOfPrincipals" From /var/log/dirsrv/slapd-TESTRELM-COM/access: [13/Mar/2012:19:17:15 -0400] conn=15 op=639 SRCH base="idnsName=_ldap._tcp,idnsname=testrelm.com,cn=dns,dc=testrelm,dc=com" scope=0 filter="(objectClass=idnsRecord)" attrs=ALL [13/Mar/2012:19:17:15 -0400] conn=15 op=639 RESULT err=0 tag=101 nentries=1 etime=0 [13/Mar/2012:19:17:15 -0400] conn=15 op=640 SRCH base="idnsName=ibm-ls22-05,idnsname=testrelm.com,cn=dns,dc=testrelm,dc=com" scope=0 filter="(objectClass=idnsRecord)" attrs=ALL [13/Mar/2012:19:17:15 -0400] conn=15 op=640 RESULT err=0 tag=101 nentries=1 etime=0 [13/Mar/2012:19:17:15 -0400] conn=15 op=641 SRCH base="idnsname=testrelm.com,cn=dns,dc=testrelm,dc=com" scope=0 filter="(objectClass=idnsRecord)" attrs=ALL [13/Mar/2012:19:17:15 -0400] conn=15 op=641 RESULT err=0 tag=101 nentries=1 etime=0 [13/Mar/2012:19:17:15 -0400] conn=31 fd=68 slot=68 connection from local to /var/run/slapd-TESTRELM-COM.socket [13/Mar/2012:19:17:15 -0400] conn=31 AUTOBIND dn="cn=Directory Manager" [13/Mar/2012:19:17:15 -0400] conn=31 op=0 BIND dn="cn=Directory Manager" method=sasl version=3 mech=EXTERNAL [13/Mar/2012:19:17:15 -0400] conn=31 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="cn=Directory Manager" [13/Mar/2012:19:17:15 -0400] conn=31 op=1 SRCH base="cn=config,cn=ldbm database,cn=plugins,cn=config" scope=0 filter="(objectClass=*)" attrs="nsslapd-directory" [13/Mar/2012:19:17:15 -0400] conn=31 op=1 RESULT err=0 tag=101 nentries=1 etime=0 [13/Mar/2012:19:17:15 -0400] conn=31 op=2 UNBIND [13/Mar/2012:19:17:15 -0400] conn=31 op=2 fd=68 closed - U1 [13/Mar/2012:19:17:15 -0400] conn=32 fd=76 slot=76 connection from local to /var/run/slapd-TESTRELM-COM.socket [13/Mar/2012:19:17:15 -0400] conn=32 AUTOBIND dn="cn=Directory Manager" [13/Mar/2012:19:17:15 -0400] conn=32 op=0 BIND dn="cn=Directory Manager" method=sasl version=3 mech=EXTERNAL [13/Mar/2012:19:17:15 -0400] conn=32 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="cn=Directory Manager" [13/Mar/2012:19:17:15 -0400] conn=32 op=1 SRCH base="cn=config,cn=ldbm database,cn=plugins,cn=config" scope=0 filter="(objectClass=*)" attrs="nsslapd-directory" [13/Mar/2012:19:17:15 -0400] conn=32 op=1 RESULT err=0 tag=101 nentries=1 etime=0 [13/Mar/2012:19:17:15 -0400] conn=32 op=2 SRCH base="cn=s4u2proxy,cn=etc,dc=testrelm,dc=com" scope=0 filter="(objectClass=*)" attrs="* aci attributeTypes objectClasses aci" [13/Mar/2012:19:17:15 -0400] conn=32 op=2 RESULT err=0 tag=101 nentries=1 etime=0 [13/Mar/2012:19:17:15 -0400] conn=32 op=3 SRCH base="cn=ipa-http-delegation,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com" scope=0 filter="(objectClass=*)" attrs="* aci attributeTypes objectClasses aci" [13/Mar/2012:19:17:15 -0400] conn=32 op=3 RESULT err=32 tag=101 nentries=0 etime=0 [13/Mar/2012:19:17:15 -0400] conn=32 op=4 ADD dn="cn=ipa-http-delegation,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com" [13/Mar/2012:19:17:15 -0400] conn=32 op=4 RESULT err=65 tag=105 nentries=0 etime=0 [13/Mar/2012:19:17:15 -0400] conn=32 op=5 SRCH base="cn=ipa-ldap-delegation-targets,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com" scope=0 filter="(objectClass=*)" attrs="* aci attributeTypes objectClasses aci" [13/Mar/2012:19:17:15 -0400] conn=32 op=5 RESULT err=32 tag=101 nentries=0 etime=0 [13/Mar/2012:19:17:15 -0400] conn=32 op=6 ADD dn="cn=ipa-ldap-delegation-targets,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com" [13/Mar/2012:19:17:15 -0400] conn=32 op=6 RESULT err=65 tag=105 nentries=0 etime=0 [13/Mar/2012:19:17:15 -0400] conn=32 op=7 UNBIND [13/Mar/2012:19:17:15 -0400] conn=32 op=7 fd=76 closed - U1 [13/Mar/2012:19:17:32 -0400] conn=15 op=643 SRCH base="cn=dns,dc=testrelm,dc=com" scope=2 filter="(&(objectClass=idnsZone)(idnsZoneActive=TRUE))" attrs="idnsName idnsUpdatePolicy idnsallowquery idnsallowtransfer" [13/Mar/2012:19:17:32 -0400] conn=15 op=643 RESULT err=0 tag=101 nentries=4 etime=0 [13/Mar/2012:19:18:02 -0400] conn=15 op=645 SRCH base="cn=dns,dc=testrelm,dc=com" scope=2 filter="(&(objectClass=idnsZone)(idnsZoneActive=TRUE))" attrs="idnsName idnsUpdatePolicy idnsallowquery idnsallowtransfer" [13/Mar/2012:19:18:02 -0400] conn=15 op=645 RESULT err=0 tag=101 nentries=4 etime=0 [13/Mar/2012:19:18:32 -0400] conn=15 op=647 SRCH base="cn=dns,dc=testrelm,dc=com" scope=2 filter="(&(objectClass=idnsZone)(idnsZoneActive=TRUE))" attrs="idnsName idnsUpdatePolicy idnsallowquery idnsallowtransfer" [13/Mar/2012:19:18:32 -0400] conn=15 op=647 RESULT err=0 tag=101 nentries=4 etime=0 This is enough information. It is missing schema for some reason. Upstream ticket: https://fedorahosted.org/freeipa/ticket/2530 Can you compress and attach /var/log/ipaupgrade.log? Also, can you provide the output from the yum upgrade ipa*? What packages are updated (particularly interested in starting and ending versions of 389-ds-base and krb5-*)? I'm unable to reproduce but I'm starting out with an otherwise updated system. Created attachment 569976 [details]
ipaupgrade.log
Created attachment 569977 [details]
yum.log for more complete listing of what was updated
Created attachment 569978 [details]
partial output of yum update ipa
I don't have all of the output from the yum update ipa* command because my 10000 line scroll buffer just wasn't enough. I attached what I did have though. And if needed, I can reproduce this on another server. I do see some errors in the ipaupgrade.log file though about starting dirsrv. This upgrade was attempted with everything running. Could that be causing that issue? The upgrade failed because the IPA dirsrv instance would not restart. [13/Mar/2012:16:19:43 -0400] createprlistensockets - PR_Bind() on localhost file /var/run/slapd-TESTRELM-COM.socket failed: Netscape Portable Runtime error -5982 (Local Network address is in use.) I'm not sure what would cause that to be considered in use since it apparently successfully shut down in the previous step. 389-ds-base is being upgraded in the same rpm transaction, I wonder if that is related. Seems like I've seen errors or warnings (at least) for that socket file. Pretty sure I had to delete it to be able to cleanly restart. Maybe the stop didn't clean up the socket file and that caused the failure to start? I'll look at that on a test box I'm setting up for this. (In reply to comment #11) > The upgrade failed because the IPA dirsrv instance would not restart. > > [13/Mar/2012:16:19:43 -0400] createprlistensockets - PR_Bind() on localhost > file /var/run/slapd-TESTRELM-COM.socket failed: Netscape Portable Runtime error > -5982 (Local Network address is in use.) > > I'm not sure what would cause that to be considered in use since it apparently > successfully shut down in the previous step. > > 389-ds-base is being upgraded in the same rpm transaction, I wonder if that is > related. What does the script use to shutdown the directory server? Is it perhaps not waiting long enough for the directory server to be shutdown before it restarts it? It uses /sbin/service dirsrv stop. (In reply to comment #14) > It uses /sbin/service dirsrv stop. So perhaps when stop returns, it is not really stopped? Where is this code in ipa? On a test server, I was able to see dirsrv not starting after upgrade. This is what I saw in that test when (and after) I was trying to get dirsrv to start 1. When I removed the /var/run/slapd-TESTRELM-COM.socket file, it could start. 2. If I moved the good socket file out of the way and copied the old one back, it failed to start. 3. If I moved the bad socket file out of the way and moved the good one back, it would start. 4. Moving bad one back again reproduced the failure to start again. I'm still testing some other options but, thought I'd share that info in case it sparks something. (In reply to comment #16) > On a test server, I was able to see dirsrv not starting after upgrade. This is > what I saw in that test when (and after) I was trying to get dirsrv to start > > 1. When I removed the /var/run/slapd-TESTRELM-COM.socket file, it could start. > 2. If I moved the good socket file out of the way and copied the old one back, > it failed to start. > 3. If I moved the bad socket file out of the way and moved the good one back, > it would start. > 4. Moving bad one back again reproduced the failure to start again. > > > I'm still testing some other options but, thought I'd share that info in case > it sparks something. I'm not sure what you mean by "good socket file" and "bad socket file" good = one that dirsrv would start with
bad = one that dirsrv would not start with
I mv'd them out of the way and back into place for that testing...that was a guess anyway and wasn't sure what to expect.
Also,
Trying:
1. <known working 2.1.3 install with some test data>
2. add 6.3 test repos
3. yum update '389-ds-*'
4. service dirsrv restart
5. service dirsrv stop
6. rm /var/run/slapd-TESTRELM-COM.socket
7. service dirsrv start
8. ipactl restart
9. yum update 'ipa*'
no dice.
[root@spoore-dvm1 ipa-upgrade]# ipa user-find
ipa: ERROR: Kerberos error: ('Unspecified GSS failure. Minor code may provide
more information', 851968)/("Cannot contact any KDC for realm 'TESTRELM.COM'",
-1765328228)
[root@spoore-dvm1 ipa-upgrade]# ipactl status
Directory Service: STOPPED
Unknown error when retrieving list of services from LDAP: [Errno 111]
Connection refused
[root@spoore-dvm1 ipa-upgrade]# ipactl restart
Restarting Directory Service
Shutting down dirsrv:
PKI-IPA... [ OK ]
TESTRELM-COM... server already stopped [FAILED]
*** Error: 1 instance(s) unsuccessfully stopped [FAILED]
Starting dirsrv:
PKI-IPA... [ OK ]
TESTRELM-COM...[14/Mar/2012:13:41:30 -0500] createprlistensockets -
PR_Bind() on localhost file /var/run/slapd-TESTRELM-COM.socket failed: Netscape
Portable Runtime error -5982 (Local Network address is in use.)
[FAILED]
*** Warning: 1 instance(s) failed to start
Failed to read data from Directory Service: Unknown error when retrieving list
of services from LDAP: [Errno 111] Connection refused
Shutting down
Shutting down dirsrv:
PKI-IPA... [ OK ]
TESTRELM-COM... server already stopped [FAILED]
*** Error: 1 instance(s) unsuccessfully stopped [FAILED]
[root@spoore-dvm1 ipa-upgrade]# rm /var/run/slapd-TESTRELM-COM.socket
rm: remove socket `/var/run/slapd-TESTRELM-COM.socket'? y
[root@spoore-dvm1 ipa-upgrade]# ipactl start
Starting Directory Service
Starting dirsrv:
PKI-IPA... [ OK ]
TESTRELM-COM... [ OK ]
Starting KDC Service
Starting Kerberos 5 KDC: [ OK ]
Starting KPASSWD Service
Starting Kerberos 5 Admin Server: [ OK ]
Starting DNS Service
Starting named: named: already running [ OK ]
Starting MEMCACHE Service
Starting HTTP Service
Starting httpd:
Starting CA Service
Starting pki-ca: [ OK ]
[root@spoore-dvm1 ipa-upgrade]# ipactl restart
Restarting Directory Service
Shutting down dirsrv:
PKI-IPA... [ OK ]
TESTRELM-COM... [ OK ]
Starting dirsrv:
PKI-IPA... [ OK ]
TESTRELM-COM... [ OK ]
Restarting KDC Service
Stopping Kerberos 5 KDC: [ OK ]
Starting Kerberos 5 KDC: [ OK ]
Restarting KPASSWD Service
Stopping Kerberos 5 Admin Server: [ OK ]
Starting Kerberos 5 Admin Server: [ OK ]
Restarting DNS Service
Stopping named: . [ OK ]
Starting named: [ OK ]
Restarting MEMCACHE Service
Stopping ipa_memcached: [ OK ]
Starting ipa_memcached: [ OK ]
Restarting HTTP Service
Stopping httpd: [ OK ]
Starting httpd: [Wed Mar 14 13:42:09 2012] [warn] worker ajp://localhost:9447/
already used by another worker
[Wed Mar 14 13:42:09 2012] [warn] worker ajp://localhost:9447/ already used by
another worker
[ OK ]
Restarting CA Service
Stopping pki-ca: [ OK ]
Starting pki-ca: [ OK ]
[root@spoore-dvm1 ipa-upgrade]# ipa user-find
ipa: ERROR: Kerberos error: ('Unspecified GSS failure. Minor code may provide
more information', 851968)/('Ticket not yet valid', -1765328351)
[root@spoore-dvm1 ipa-upgrade]# ipactl status
Directory Service: RUNNING
KDC Service: RUNNING
KPASSWD Service: RUNNING
DNS Service: RUNNING
MEMCACHE Service: RUNNING
HTTP Service: RUNNING
CA Service: RUNNING
And I see the same type of socket file errors in the ipaupgrade.log there as
well:
2012-03-14T18:39:42Z DEBUG stdout=Starting dirsrv:
PKI-IPA...[ OK ]
TESTRELM-COM...[FAILED]
*** Warning: 1 instance(s) failed to start
2012-03-14T18:39:42Z DEBUG stderr=[14/Mar/2012:13:39:41 -0500] - Information:
Non-Secure Port Disabled
[14/Mar/2012:13:39:41 -0500] createprlistensockets - PR_Bind() on localhost
file /var/run/slapd-TESTRELM-COM.socket
failed: Netscape Portable Runtime error -5982 (Local Network address is in
use.)
2012-03-14T18:39:42Z DEBUG duration: 1 seconds
2012-03-14T18:39:42Z DEBUG [5/8]: upgrading server
2012-03-14T18:39:52Z ERROR Upgrade failed with Unable to connect to LDAP server
ldapi://%2fvar%2frun%2fslapd-TESTRE
LM-COM.socket
2012-03-14T18:39:52Z DEBUG Traceback (most recent call last):
File "/usr/lib/python2.6/site-packages/ipaserver/install/upgradeinstance.py",
line 104, in __upgrade
ld = ldapupdate.LDAPUpdate(dm_password='', ldapi=True,
live_run=self.live_run, plugins=True)
File "/usr/lib/python2.6/site-packages/ipaserver/install/ldapupdate.py", line
133, in __init__
raise RuntimeError("Unable to connect to LDAP server %s" % fqdn)
RuntimeError: Unable to connect to LDAP server
ldapi://%2fvar%2frun%2fslapd-TESTRELM-COM.socket
richm, the code is a bit abstracted out but the actual execution is done in ipapython/platform/redhat.py::RedHatService::stop() This just forks out /sbin/service dirsrv stop and returns. The socket files are labeled under selinux policy. In general, you cannot use the mv command because it doesn't label the files properly. You can if you know what you're doing (know the selinux commands to label the file properly after the mv). Removing the socket file and letting the directory server create it should work and should label the file properly. Do you have any selinux AVC messages? I thought mv handled the selinux context for the files. Is it not reliable or you're saying it never handles the labels?
And I do actually see some AVC messages here that match the times of some of the errors from my last comment.
# ausearch -m AVC -ts 03/14/2012 13:30
----
time->Wed Mar 14 13:39:41 2012
type=SYSCALL msg=audit(1331750381.939:38509): arch=c000003e syscall=87 success=no exit=-13 a0=14a8aa2 a1=148bde2 a2=45 a3=7fff9bfb31f0 items=0 ppid=4092 pid=4093 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts0 ses=1 comm="ns-slapd" exe="/usr/sbin/ns-slapd" subj=unconfined_u:system_r:dirsrv_t:s0 key=(null)
type=AVC msg=audit(1331750381.939:38509): avc: denied { unlink } for pid=4093 comm="ns-slapd" name="slapd-TESTRELM-COM.socket" dev=dm-1 ino=47596 scontext=unconfined_u:system_r:dirsrv_t:s0 tcontext=unconfined_u:object_r:var_run_t:s0 tclass=sock_file
----
time->Wed Mar 14 13:39:54 2012
type=SYSCALL msg=audit(1331750394.598:38510): arch=c000003e syscall=87 success=no exit=-13 a0=163fc02 a1=1622e52 a2=45 a3=7fff948f8b50 items=0 ppid=4221 pid=4222 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts0 ses=1 comm="ns-slapd" exe="/usr/sbin/ns-slapd" subj=unconfined_u:system_r:dirsrv_t:s0 key=(null)
type=AVC msg=audit(1331750394.598:38510): avc: denied { unlink } for pid=4222 comm="ns-slapd" name="slapd-TESTRELM-COM.socket" dev=dm-1 ino=47596 scontext=unconfined_u:system_r:dirsrv_t:s0 tcontext=unconfined_u:object_r:var_run_t:s0 tclass=sock_file
----
time->Wed Mar 14 13:41:30 2012
type=SYSCALL msg=audit(1331750490.937:38518): arch=c000003e syscall=87 success=no exit=-13 a0=215ec02 a1=2141e52 a2=45 a3=7fff4cf89600 items=0 ppid=4483 pid=4484 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts0 ses=1 comm="ns-slapd" exe="/usr/sbin/ns-slapd" subj=unconfined_u:system_r:dirsrv_t:s0 key=(null)
type=AVC msg=audit(1331750490.937:38518): avc: denied { unlink } for pid=4484 comm="ns-slapd" name="slapd-TESTRELM-COM.socket" dev=dm-1 ino=47596 scontext=unconfined_u:system_r:dirsrv_t:s0 tcontext=unconfined_u:object_r:var_run_t:s0 tclass=sock_file
(In reply to comment #21) > I thought mv handled the selinux context for the files. Is it not reliable or > you're saying it never handles the labels? I thought mv did not relabel the files. Nathan, can you clarify? > > And I do actually see some AVC messages here that match the times of some of > the errors from my last comment. This sounds vaguely familiar - what version of selinux-policy do you have? > > # ausearch -m AVC -ts 03/14/2012 13:30 > ---- > time->Wed Mar 14 13:39:41 2012 > type=SYSCALL msg=audit(1331750381.939:38509): arch=c000003e syscall=87 > success=no exit=-13 a0=14a8aa2 a1=148bde2 a2=45 a3=7fff9bfb31f0 items=0 > ppid=4092 pid=4093 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 > fsgid=0 tty=pts0 ses=1 comm="ns-slapd" exe="/usr/sbin/ns-slapd" > subj=unconfined_u:system_r:dirsrv_t:s0 key=(null) > type=AVC msg=audit(1331750381.939:38509): avc: denied { unlink } for > pid=4093 comm="ns-slapd" name="slapd-TESTRELM-COM.socket" dev=dm-1 ino=47596 > scontext=unconfined_u:system_r:dirsrv_t:s0 > tcontext=unconfined_u:object_r:var_run_t:s0 tclass=sock_file > > ---- > time->Wed Mar 14 13:39:54 2012 > type=SYSCALL msg=audit(1331750394.598:38510): arch=c000003e syscall=87 > success=no exit=-13 a0=163fc02 a1=1622e52 a2=45 a3=7fff948f8b50 items=0 > ppid=4221 pid=4222 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 > fsgid=0 tty=pts0 ses=1 comm="ns-slapd" exe="/usr/sbin/ns-slapd" > subj=unconfined_u:system_r:dirsrv_t:s0 key=(null) > type=AVC msg=audit(1331750394.598:38510): avc: denied { unlink } for > pid=4222 comm="ns-slapd" name="slapd-TESTRELM-COM.socket" dev=dm-1 ino=47596 > scontext=unconfined_u:system_r:dirsrv_t:s0 > tcontext=unconfined_u:object_r:var_run_t:s0 tclass=sock_file > > ---- > time->Wed Mar 14 13:41:30 2012 > type=SYSCALL msg=audit(1331750490.937:38518): arch=c000003e syscall=87 > success=no exit=-13 a0=215ec02 a1=2141e52 a2=45 a3=7fff4cf89600 items=0 > ppid=4483 pid=4484 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 > fsgid=0 tty=pts0 ses=1 comm="ns-slapd" exe="/usr/sbin/ns-slapd" > subj=unconfined_u:system_r:dirsrv_t:s0 key=(null) > type=AVC msg=audit(1331750490.937:38518): avc: denied { unlink } for > pid=4484 comm="ns-slapd" name="slapd-TESTRELM-COM.socket" dev=dm-1 ino=47596 > scontext=unconfined_u:system_r:dirsrv_t:s0 > tcontext=unconfined_u:object_r:var_run_t:s0 tclass=sock_file This is the version of selinux-policy installed selinux-policy-3.7.19-138.el6.noarch (In reply to comment #22) > (In reply to comment #21) > > I thought mv handled the selinux context for the files. Is it not reliable or > > you're saying it never handles the labels? > > I thought mv did not relabel the files. Nathan, can you clarify? Files are labelled when they are created. When you create a file, it is labelled based off of the location is was created in. When you move it, it's original label is retained, even if the fcontext rule for the destination says to use a different label. Copying a file will cause the new copy to be labelled appropriately for it's destination. > > > > > And I do actually see some AVC messages here that match the times of some of > > the errors from my last comment. > > This sounds vaguely familiar - what version of selinux-policy do you have? > > > > > # ausearch -m AVC -ts 03/14/2012 13:30 > > ---- > > time->Wed Mar 14 13:39:41 2012 > > type=SYSCALL msg=audit(1331750381.939:38509): arch=c000003e syscall=87 > > success=no exit=-13 a0=14a8aa2 a1=148bde2 a2=45 a3=7fff9bfb31f0 items=0 > > ppid=4092 pid=4093 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 > > fsgid=0 tty=pts0 ses=1 comm="ns-slapd" exe="/usr/sbin/ns-slapd" > > subj=unconfined_u:system_r:dirsrv_t:s0 key=(null) > > type=AVC msg=audit(1331750381.939:38509): avc: denied { unlink } for > > pid=4093 comm="ns-slapd" name="slapd-TESTRELM-COM.socket" dev=dm-1 ino=47596 > > scontext=unconfined_u:system_r:dirsrv_t:s0 > > tcontext=unconfined_u:object_r:var_run_t:s0 tclass=sock_file > > > > ---- > > time->Wed Mar 14 13:39:54 2012 > > type=SYSCALL msg=audit(1331750394.598:38510): arch=c000003e syscall=87 > > success=no exit=-13 a0=163fc02 a1=1622e52 a2=45 a3=7fff948f8b50 items=0 > > ppid=4221 pid=4222 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 > > fsgid=0 tty=pts0 ses=1 comm="ns-slapd" exe="/usr/sbin/ns-slapd" > > subj=unconfined_u:system_r:dirsrv_t:s0 key=(null) > > type=AVC msg=audit(1331750394.598:38510): avc: denied { unlink } for > > pid=4222 comm="ns-slapd" name="slapd-TESTRELM-COM.socket" dev=dm-1 ino=47596 > > scontext=unconfined_u:system_r:dirsrv_t:s0 > > tcontext=unconfined_u:object_r:var_run_t:s0 tclass=sock_file > > > > ---- > > time->Wed Mar 14 13:41:30 2012 > > type=SYSCALL msg=audit(1331750490.937:38518): arch=c000003e syscall=87 > > success=no exit=-13 a0=215ec02 a1=2141e52 a2=45 a3=7fff4cf89600 items=0 > > ppid=4483 pid=4484 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 > > fsgid=0 tty=pts0 ses=1 comm="ns-slapd" exe="/usr/sbin/ns-slapd" > > subj=unconfined_u:system_r:dirsrv_t:s0 key=(null) > > type=AVC msg=audit(1331750490.937:38518): avc: denied { unlink } for > > pid=4484 comm="ns-slapd" name="slapd-TESTRELM-COM.socket" dev=dm-1 ino=47596 > > scontext=unconfined_u:system_r:dirsrv_t:s0 > > tcontext=unconfined_u:object_r:var_run_t:s0 tclass=sock_file I think the ldapi socket file is labelled incorrectly. This does sound familiar. Please try running the following command: semanage fcontext -l | grep /var/run/slapd I believe that this is a duplicate of bug 799102 Looks very similar to 799102. # semanage fcontext -l | grep /var/run/slapd /var/run/slapd\.args regular file system_u:object_r:slapd_var_run_t:s0 /var/run/slapd\.pid regular file system_u:object_r:slapd_var_run_t:s0 I don't see anything for socket files but, it is getting labelled as dirsrv_var_run_t when it's created by a starting the dirsrv service. So, am I reading the AVC correctly? ns-slapd is trying to run an unlink syscall as dirsrv_t. This fails because the syscall is against the directory (not the file) so it's target context is var_run_t instead of dirsrv_t or dirsrv_var_run_t. Is that right? So this is killing my upgrades when the service is restarted at some point because ns-slapd can't delete the file? That causes the failure to restart at the point during the upgrade when it's supposed to update ldap and the delegation gets lost? Is that close? (In reply to comment #26) > Looks very similar to 799102. > > # semanage fcontext -l | grep /var/run/slapd > /var/run/slapd\.args regular file > system_u:object_r:slapd_var_run_t:s0 > /var/run/slapd\.pid regular file > system_u:object_r:slapd_var_run_t:s0 > > I don't see anything for socket files but, it is getting labelled as > dirsrv_var_run_t when it's created by a starting the dirsrv service. > > So, am I reading the AVC correctly? > > ns-slapd is trying to run an unlink syscall as dirsrv_t. This fails because > the syscall is against the directory (not the file) so it's target context is > var_run_t instead of dirsrv_t or dirsrv_var_run_t. > > Is that right? Close. The ns-slapd program (running as dirsrv_t) is attempting to unlink the slapd-TESTRELM-COM.socket file (labelled as var_run_t). A program running as dirsrv_t is not allowed to do this. We expect the socket file to be labelled as dirsrv_var_run_t, which we have permission to unlink. > > So this is killing my upgrades when the service is restarted at some point > because ns-slapd can't delete the file? That causes the failure to restart at > the point during the upgrade when it's supposed to update ldap and the > delegation gets lost? > > Is that close? Yes. If the socket file is around at start up, we try to remove it. The SELinux policy is preventing us from removing it, so restart fails. What I believe is happening is that the socket file is being relabelled by restorecon during upgrade. The fcontext rules in the policy don't have anything to properly label the ldapi socket file, so it uses the label from it's parent directory (/var/run), which is var_run_t. The policy has some special transition rules in place which causes the socket file to be created with the dirsrv_var_run_t context only when it is created by a dirsrv_t program. You would be able to easily simulate the problem by running the following command when your ns-slapd is up and running properly: restorecon -v /var/run/slapd-TESTRELM-COM.socket This will cause the label to change to var_run_t, which would not allow ns-slapd to use the file anymore. A policy rule needs to be put in place to prevent restorecon from changing the label. (In reply to comment #27) > (In reply to comment #26) > > Looks very similar to 799102. > > > > # semanage fcontext -l | grep /var/run/slapd > > /var/run/slapd\.args regular file > > system_u:object_r:slapd_var_run_t:s0 > > /var/run/slapd\.pid regular file > > system_u:object_r:slapd_var_run_t:s0 > > > > I don't see anything for socket files but, it is getting labelled as > > dirsrv_var_run_t when it's created by a starting the dirsrv service. > > > > So, am I reading the AVC correctly? > > > > ns-slapd is trying to run an unlink syscall as dirsrv_t. This fails because > > the syscall is against the directory (not the file) so it's target context is > > var_run_t instead of dirsrv_t or dirsrv_var_run_t. > > > > Is that right? > > Close. The ns-slapd program (running as dirsrv_t) is attempting to unlink the > slapd-TESTRELM-COM.socket file (labelled as var_run_t). A program running as > dirsrv_t is not allowed to do this. We expect the socket file to be labelled > as dirsrv_var_run_t, which we have permission to unlink. > > > > > So this is killing my upgrades when the service is restarted at some point > > because ns-slapd can't delete the file? That causes the failure to restart at > > the point during the upgrade when it's supposed to update ldap and the > > delegation gets lost? > > > > Is that close? > > Yes. If the socket file is around at start up, we try to remove it. The > SELinux policy is preventing us from removing it, so restart fails. > > What I believe is happening is that the socket file is being relabelled by > restorecon during upgrade. The fcontext rules in the policy don't have > anything to properly label the ldapi socket file, so it uses the label from > it's parent directory (/var/run), which is var_run_t. The policy has some > special transition rules in place which causes the socket file to be created > with the dirsrv_var_run_t context only when it is created by a dirsrv_t > program. > Ok, that makes much more sense now. I was getting confused as to why it was ever showing the error for var_run_t. But, if it's restoring context during upgrade, that makes sense now considering no policy in place for socket files. > You would be able to easily simulate the problem by running the following > command when your ns-slapd is up and running properly: > > restorecon -v /var/run/slapd-TESTRELM-COM.socket > > This will cause the label to change to var_run_t, which would not allow > ns-slapd to use the file anymore. A policy rule needs to be put in place to > prevent restorecon from changing the label. Yes, I did see that yesterday (although with rm, then touch). So, that will be addressed in bug 799102 right? Thanks Bug 799102 has been addressed in selinux-policy-3.7.19-142.el6. Could you please test with that package to confirm that it resolves this issue? If so, you can close this bug. Before I tried an upgrade of ipa, I ran 'ipactl restart' and had issues:
# rpm -q selinux-policy
selinux-policy-3.7.19-142.el6.noarch
# ipactl restart
Restarting Directory Service
Shutting down dirsrv:
PKI-IPA...[ OK ]
TESTRELM-COM...[ OK ]
Starting dirsrv:
PKI-IPA...[ OK ]
TESTRELM-COM...[21/Mar/2012:15:32:03 -0400] createprlistensockets - PR_Bind() on localhost file /var/run/slapd-TESTRELM-COM.socket failed: Netscape Portable Runtime error -5982 (Local Network address is in use.)
[FAILED]
*** Warning: 1 instance(s) failed to start
Failed to read data from Directory Service: Failed to get list of services to probe status:
Directory Server is stopped
Shutting down
Shutting down dirsrv:
PKI-IPA...[ OK ]
TESTRELM-COM... server already stopped[FAILED]
*** Error: 1 instance(s) unsuccessfully stopped[FAILED]
# ausearch -m AVC
----
time->Wed Mar 21 15:32:03 2012
type=SYSCALL msg=audit(1332358323.624:202): arch=c000003e syscall=87 success=no exit=-13 a0=f68fd2 a1=f682f2 a2=45 a3=6b636f732e4d4f43 items=0 ppid=14688 pid=14689 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts0 ses=10 comm="ns-slapd" exe="/usr/sbin/ns-slapd" subj=unconfined_u:system_r:dirsrv_t:s0 key=(null)
type=AVC msg=audit(1332358323.624:202): avc: denied { unlink } for pid=14689 comm="ns-slapd" name="slapd-TESTRELM-COM.socket" dev=dm-0 ino=1966792 scontext=unconfined_u:system_r:dirsrv_t:s0 tcontext=unconfined_u:object_r:slapd_var_run_t:s0 tclass=sock_file
# semanage fcontext -l | grep /var/run/slapd
/var/run/slapd.* socket system_u:object_r:slapd_var_run_t:s0
/var/run/slapd\.args regular file system_u:object_r:slapd_var_run_t:s0
/var/run/slapd\.pid regular file system_u:object_r:slapd_var_run_t:s0
So, was that expected? I'd thought that some additional rules had been suggest to allow the slapd_var_run_t label to work here. How can I check if the rules from bug 799102 comment 6 were implemented? I don't seem to be able to reproduce this issue anymore after some ipa-server, 389-ds-base, and selinux-policy updates. Was something fixed in the order of start/stop that corrected this without the selinux-policy dirsrv module update? Since I can no longer see the issue opened here, I'm just curious if this was fixed in dirsrv's handling of the socket file or something similar? # rpm -q ipa-server 389-ds-base selinux-policy ipa-server-2.2.0-8.el6.x86_64 389-ds-base-1.2.10.2-4.el6.x86_64 selinux-policy-3.7.19-142.el6.noarch # ausearch -m avc <no matches> # ls -Z /var/run/slapd-TESTRELM-COM.socket srw-rw-rw-. root root unconfined_u:object_r:dirsrv_var_run_t:s0 /var/run/slapd-TESTRELM-COM.socket # semanage fcontext -l|grep /var/run/slapd /var/run/slapd.* socket system_u:object_r:slapd_var_run_t:s0 /var/run/slapd\.args regular file system_u:object_r:slapd_var_run_t:s0 /var/run/slapd\.pid regular file system_u:object_r:slapd_var_run_t:s0 # bunzip2 -c /usr/share/selinux/targeted/dirsrv.pp.bz2 > /tmp/dirsrv.pp # strings /tmp/dirsrv.pp|grep slap slapd_var_run_t slapd_t slapd_var_run_t slapd_t /usr/sbin/ns-slapd -- system_u:object_r:dirsrv_exec_t:s0 # yum -y update 'ipa*' <snip> Installed products updated. Updated: bind-dyndb-ldap.x86_64 0:1.1.0-0.5.b1.el6 ipa-admintools.x86_64 0:2.2.0-8.el6 ipa-client.x86_64 0:2.2.0-8.el6 ipa-python.x86_64 0:2.2.0-8.el6 ipa-server.x86_64 0:2.2.0-8.el6 ipa-server-selinux.x86_64 0:2.2.0-8.el6 Dependency Updated: 389-ds-base.x86_64 0:1.2.10.2-4.el6 389-ds-base-libs.x86_64 0:1.2.10.2-4.el6 bind.x86_64 32:9.8.2-0.6.rc1.el6 bind-libs.x86_64 32:9.8.2-0.6.rc1.el6 bind-utils.x86_64 32:9.8.2-0.6.rc1.el6 krb5-devel.x86_64 0:1.9-32.el6 krb5-libs.x86_64 0:1.9-32.el6 krb5-pkinit-openssl.x86_64 0:1.9-32.el6 krb5-server.x86_64 0:1.9-32.el6 krb5-server-ldap.x86_64 0:1.9-32.el6 krb5-workstation.x86_64 0:1.9-32.el6 libipa_hbac.x86_64 0:1.8.0-20.el6 libipa_hbac-python.x86_64 0:1.8.0-20.el6 mod_auth_kerb.x86_64 0:5.4-9.el6 pki-ca.noarch 0:9.0.3-24.el6 pki-common.noarch 0:9.0.3-24.el6 pki-java-tools.noarch 0:9.0.3-24.el6 pki-native-tools.x86_64 0:9.0.3-24.el6 pki-selinux.noarch 0:9.0.3-24.el6 pki-setup.noarch 0:9.0.3-24.el6 pki-silent.noarch 0:9.0.3-24.el6 pki-symkey.x86_64 0:9.0.3-24.el6 pki-util.noarch 0:9.0.3-24.el6 sssd.x86_64 0:1.8.0-20.el6 sssd-client.x86_64 0:1.8.0-20.el6 Complete! </snip> # ipactl restart Restarting Directory Service Shutting down dirsrv: PKI-IPA... [ OK ] TESTRELM-COM... [ OK ] Starting dirsrv: PKI-IPA... [ OK ] TESTRELM-COM... [ OK ] Restarting KDC Service Stopping Kerberos 5 KDC: [ OK ] Starting Kerberos 5 KDC: [ OK ] Restarting KPASSWD Service Stopping Kerberos 5 Admin Server: [ OK ] Starting Kerberos 5 Admin Server: [ OK ] Restarting DNS Service Stopping named: . [ OK ] Starting named: [ OK ] Restarting MEMCACHE Service Stopping ipa_memcached: [ OK ] Starting ipa_memcached: [ OK ] Restarting HTTP Service Stopping httpd: [ OK ] Starting httpd: [Thu Apr 05 14:03:06 2012] [warn] worker ajp://localhost:9447/ already used by another worker [Thu Apr 05 14:03:06 2012] [warn] worker ajp://localhost:9447/ already used by another worker [ OK ] Restarting CA Service Stopping pki-ca: [ OK ] Starting pki-ca: [ OK ] # ipa user-find --------------- 3 users matched --------------- User login: admin Last name: Administrator Home directory: /home/admin Login shell: /bin/bash UID: 1392000000 GID: 1392000000 Account disabled: False Password: True Kerberos keys available: True User login: jack First name: First Last name: Last Home directory: /home/jack Login shell: /bin/sh UID: 1392000003 GID: 1392000003 Account disabled: False Password: True Kerberos keys available: True User login: jill First name: First Last name: Last Home directory: /home/jill Login shell: /bin/sh UID: 1392000004 GID: 1392000004 Account disabled: False Password: True Kerberos keys available: True ---------------------------- Number of entries returned 3 ---------------------------- (In reply to comment #32) > I don't seem to be able to reproduce this issue anymore after some ipa-server, > 389-ds-base, and selinux-policy updates. Was something fixed in the order of > start/stop that corrected this without the selinux-policy dirsrv module update? > > Since I can no longer see the issue opened here, I'm just curious if this was > fixed in dirsrv's handling of the socket file or something similar? > No, nothing changed in 389-ds-base around this. You should be able to reproduce still by doing a restorecon on /var/run/slapd.* while the dirsrv service is running. That will cause the socket file to be relabelled as slapd_var_run_t. If you then try to restart dirsrv, you will see the AVC. Yes, that I can reproduce. But, I'm no longer seeing the issue with IPA upgrades that was caused by that from the original issue. I was wondering if maybe the setup-ds.pl moving from %posttrans to %post in 1.2.10.2-4 may have helped with this one too. Or, some other change in IPA's upgrade affected it so the socket file is no longer removed during a restart? In any case, the IPA upgrades are working but, the restorecon does switch labels as you mentioned. I am going to go ahead and close this one as WORKSFORME since I cannot reproduce the "symptom" since the following updates: ipa-server 2.2.0-5 389-ds-base 1.2.10.2-4 selinux-policy-targetd 3.7.19-142 The selinux labelling issue is addressed in bug 799102 and my test results have been posted there. |
Description of problem: IPA upgrades on RHEL6.2 from 2.1.3 to 2.2.0 seems to have an issue after upgrade. # yum -y update 'ipa*' ... # ipactl restart ... # ipa user-find ipa: ERROR: Insufficient access: KDC returned NOT_ALLOWED_TO_DELEGATE I'm hoping this is straightforward and maybe even something I missed but, I also tried updating everything as well as trying this: # ipa-ldap-updater --ldapi /usr/share/ipa/updates/30-s4u2proxy.update ipa : INFO Parsing file /usr/share/ipa/updates/30-s4u2proxy.update ipa : INFO New entry: cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : INFO New entry: cn=ipa-http-delegation,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : ERROR Add failure 'NoneType' object is not callable ipa : INFO New entry: cn=ipa-ldap-delegation-targets,cn=s4u2proxy,cn=etc,dc=testrelm,dc=com ipa : ERROR Add failure 'NoneType' object is not callable ipa : INFO Update complete Version-Release number of selected component (if applicable): RHEL 6.2 pointing to RHEL 6.3 test repo and repo containing IPA 2.2.0-3 rpms. How reproducible: So far, always. Steps to Reproduce: 1. <Install IPA on RHEL6.2 server> 2. kinit admin 3. <add some content (users, groups, etc)> 4. <add yum repo with RHEL 6.3 and 2.2.0-3 rpms> 5. yum -y update 'ipa*' 6. ipactl restart 7. ipa user-find Actual results: command returns the following: ipa: ERROR: Insufficient access: KDC returned NOT_ALLOWED_TO_DELEGATE Expected results: ipa command to run and return normal output. Additional info: /var/log/messages entry: Mar 13 16:49:53 ibm-ls22-05 httpd: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (KDC returned error string: NOT_ALLOWED_TO_DELEGATE) /var/log/krb5kdc.log entries: Mar 13 16:49:53 HOSTNAME krb5kdc[17278](info): TGS_REQ (4 etypes {18 17 16 23}) 10.34.54.41: NOT_ALLOWED_TO_DELEGATE: authtime 0, HTTP/hostname.testrelm.com for ldap/hostname.testrelm.com, Server error Mar 13 16:49:53 hostname.testrelm.com krb5kdc[17279](info): TGS_REQ (4 etypes {18 17 16 23}) 10.34.54.41: NOT_ALLOWED_TO_DELEGATE: authtime 0, HTTP/hostname.testrelm.com for ldap/hostname.testrelm.com, Server error