[Freeipa-users] krb5-server-1.9-33.el6_3.3.x86_64 prevents named from starting when selinux is enforcing

Sigbjorn Lie sigbjorn at nixtra.com
Thu Sep 20 20:30:03 UTC 2012


On 09/20/2012 10:17 PM, Rob Crittenden wrote:
> Sigbjorn Lie wrote:
>> On 09/20/2012 12:08 AM, Rob Crittenden wrote:
>>> Sigbjorn Lie wrote:
>>>> On 09/19/2012 11:05 PM, Rob Crittenden wrote:
>>>>> Sigbjorn Lie wrote:
>>>>>> On 09/19/2012 10:48 PM, Rob Crittenden wrote:
>>>>>>> Sigbjorn Lie wrote:
>>>>>>>> Hi,
>>>>>>>>
>>>>>>>> I noticed an updated krb5-server package today advertising that 
>>>>>>>> it's
>>>>>>>> fixing the issue with slow GSSAPI binds discussed earlier, so I
>>>>>>>> installed it in my test environment, set SElinux back to
>>>>>>>> enforcing in
>>>>>>>> /etc/sysconfig/selinux and rebooted.
>>>>>>>>
>>>>>>>> The named daemon does not start now. The error below was logged in
>>>>>>>> /var/log/messages:
>>>>>>>>
>>>>>>>> Sep 19 21:54:46 ipa01 named[3712]: GSSAPI Error: Unspecified GSS
>>>>>>>> failure.  Minor code may provide more information (KDC returned
>>>>>>>> error
>>>>>>>> string: PROCESS_TGS)
>>>>>>>>
>>>>>>>> I am able to start named after setting SElinux in permissive mode
>>>>>>>> (setenforce 0).
>>>>>>>>
>>>>>>>> Then to verify: I stop all IPA services (ipactl stop), reenabled
>>>>>>>> selinux
>>>>>>>> (setenforce 1), and start the IPA services (ipactl start). A new
>>>>>>>> error
>>>>>>>> is logged in /var/log/messages:
>>>>>>>>
>>>>>>>> Sep 19 22:00:49 ipa01 named[5918]: bind to LDAP server failed:
>>>>>>>> Invalid
>>>>>>>> credentials
>>>>>>>> Sep 19 22:00:49 ipa01 named[5918]: loading configuration: 
>>>>>>>> permission
>>>>>>>> denied
>>>>>>>> Sep 19 22:00:49 ipa01 named[5918]: exiting (due to fatal error)
>>>>>>>>
>>>>>>>>
>>>>>>>>  From the /var/log/krb5kdc.log:
>>>>>>>> Sep 19 21:54:46 ipa01.ix.test.com krb5kdc[3681](info): TGS_REQ (4
>>>>>>>> etypes
>>>>>>>> {18 17 16 23}) 192.168.210.20: PROCESS_TGS: authtime 0, <unknown
>>>>>>>> client>
>>>>>>>> for <unknown server>, Cannot create replay cache file
>>>>>>>> /var/tmp/krbtgt_0:
>>>>>>>> File exists
>>>>>>>> Sep 19 21:54:46 ipa01.ix.test.com krb5kdc[3681](info): TGS_REQ (4
>>>>>>>> etypes
>>>>>>>> {18 17 16 23}) 192.168.210.20: PROCESS_TGS: authtime 0, <unknown
>>>>>>>> client>
>>>>>>>> for <unknown server>, Cannot create replay cache file
>>>>>>>> /var/tmp/krbtgt_0:
>>>>>>>> File exists
>>>>>>>> Sep 19 21:54:46 ipa01.ix.test.com krb5kdc[3681](info): AS_REQ (4
>>>>>>>> etypes
>>>>>>>> {18 17 16 23}) 192.168.210.20: NEEDED_PREAUTH:
>>>>>>>> DNS/ipa01.ix.test.com at IX.TEST.COM for
>>>>>>>> krbtgt/IX.TEST.COM at IX.TEST.COM,
>>>>>>>> Additional pre-authentication required
>>>>>>>> Sep 19 21:54:46 ipa01.ix.test.com krb5kdc[3681](info): AS_REQ (4
>>>>>>>> etypes
>>>>>>>> {18 17 16 23}) 192.168.210.20: ISSUE: authtime 1348084486, etypes
>>>>>>>> {rep=18 tkt=18 ses=18}, DNS/ipa01.ix.test.com at IX.TEST.COM for
>>>>>>>> krbtgt/IX.TEST.COM at IX.TEST.COM
>>>>>>>>
>>>>>>>> /var/named/data/named.run logged nothing.
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> Any suggestions for how to troubleshoot this issue?
>>>>>>>
>>>>>>> Pure guess, but:
>>>>>>>
>>>>>>> restorecon /var/tmp/krbtgt_0
>>>>>>>
>>>>>>> rob
>>>>>> Sorry, that did not help. There seem to be a new error in the 
>>>>>> messages
>>>>>> file every time I attempt a named restart though. See below for the
>>>>>> latest:
>>>>>>
>>>>>> Sep 19 23:01:27 ipa01 named[12638]: default realm from krb5.conf
>>>>>> (IX.TEST.COM) does not match tkey-gssapi-credential
>>>>>> (DNS/ipa01.ix.test.com)
>>>>>> Sep 19 23:01:27 ipa01 named[12638]: configuring TKEY: failure
>>>>>> Sep 19 23:01:27 ipa01 named[12638]: loading configuration: failure
>>>>>> Sep 19 23:01:27 ipa01 named[12638]: exiting (due to fatal error)
>>>>>
>>>>> I'd continue to check /var/log/audit/audit.log for AVCs.
>>>>>
>>>>> rob
>>>>>
>>>>
>>>> OK, I had a quick look before I'm off for today. :)
>>>>
>>>> There's a lot of these messages, denying named access to
>>>> /var/tmp/DNS_25.
>>>>
>>>>
>>>>
>>>> type=AVC msg=audit(1348086955.397:42404): avc:  denied  { getattr } 
>>>> for
>>>> pid=11648 comm="named" path="/var/tmp/DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348086955.398:42405): avc:  denied  { read write }
>>>> for  pid=11648 comm="named" name="DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348086955.398:42405): avc:  denied  { open } for
>>>> pid=11648 comm="named" name="DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088487.524:42438): avc:  denied  { getattr } 
>>>> for
>>>> pid=12639 comm="named" path="/var/tmp/DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088487.524:42439): avc:  denied  { unlink } for
>>>> pid=12639 comm="named" name="DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088487.525:42440): avc:  denied  { getattr } 
>>>> for
>>>> pid=12639 comm="named" path="/var/tmp/DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088487.525:42441): avc:  denied  { unlink } for
>>>> pid=12639 comm="named" name="DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088487.525:42442): avc:  denied  { getattr } 
>>>> for
>>>> pid=12639 comm="named" path="/var/tmp/DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088487.525:42443): avc:  denied  { unlink } for
>>>> pid=12639 comm="named" name="DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088487.525:42444): avc:  denied  { getattr } 
>>>> for
>>>> pid=12639 comm="named" path="/var/tmp/DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088487.526:42445): avc:  denied  { unlink } for
>>>> pid=12639 comm="named" name="DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088487.526:42446): avc:  denied  { getattr } 
>>>> for
>>>> pid=12639 comm="named" path="/var/tmp/DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088487.526:42447): avc:  denied  { unlink } for
>>>> pid=12639 comm="named" name="DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088493.161:42449): avc:  denied  { getattr } 
>>>> for
>>>> pid=12667 comm="named" path="/var/tmp/DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088493.162:42450): avc:  denied  { read write }
>>>> for  pid=12667 comm="named" name="DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>> type=AVC msg=audit(1348088493.162:42450): avc:  denied  { open } for
>>>> pid=12667 comm="named" name="DNS_25" dev=dm-2 ino=132140
>>>> scontext=unconfined_u:system_r:named_t:s0
>>>> tcontext=system_u:object_r:tmp_t:s0 tclass=file
>>>>
>>>>
>>>>
>>>> I tried "restorecon /var/tmp/DNS_25", but the attributes looks the 
>>>> same
>>>> before and after:
>>>>
>>>> -rw-------. named  named  system_u:object_r:tmp_t:s0 DNS_25
>>>
>>> Ok, I'm not sure. Perhaps selinux-policy has an update available too?
>>>
>>> You may want to consider temporarily setting selinux to permissive
>>> while we sort this out if your system is otherwise unusable.
>>>
>>> rob
>>>
>> There is no more updates available for the system at all.
>>
>> I've set selinux to permissive for now.
>>
>> Please let me know when you know what else to troubleshoot. I have also
>> updated my RH support case with this thread.
>
> bind isn't my strongest suite.
>
> My guess is that this file is the ccache for bind. I'm guessing that 
> 25 is the UID of the named user. If this is the case, then it should 
> be safe to stop named, rename the file, and restart. Perhaps the 
> contexts have changed so when this gets re-created it will get fixed 
> automagically.
>
> rob
>
You guessed well!! :)

Stop named:
# service named stop

Enable selinux:
# setenforce 1

Verify that error still exists:
# service named start
Starting named:                                            [FAILED]

Rename file:
# cd /var/tmp
# mv DNS_25 DNS_25_old

Attempt to start named again:
# service named start
Starting named:                                            [  OK  ]

Voila!

A before and after shot:
# ls -lZ DNS_25*
-rw-------. named named unconfined_u:object_r:named_tmp_t:s0 DNS_25
-rw-------. named named system_u:object_r:tmp_t:s0       DNS_25_old

What's the odds that this was the entire issue and that named will now 
keep running safe and sound?


Regards,
Siggi





More information about the Freeipa-users mailing list