[Freeipa-devel] [PATCHES] 241-253 CA certificate renewal

Rob Crittenden rcritten at redhat.com
Thu Apr 10 20:06:08 UTC 2014


Some in-line, a whole ton of data appended to end.

Jan Cholasta wrote:
> On 7.4.2014 20:09, Rob Crittenden wrote:
>> Rob Crittenden wrote:
>>> Jan Cholasta wrote:
>>>> Hi,
>>>>
>>>> the attached patches implement automatic CA certificate renewal as well
>>>> as the initial version of the CA certificate management tool.
>>>>
>>>> Requires my patches 172-196.
>>>>
>>>> In order to test, you must install current git version of certmonger
>>>> (see <https://fedorahosted.org/certmonger/ticket/26>) and set
>>>> SELinux to
>>>> permissive (see <https://bugzilla.redhat.com/show_bug.cgi?id=1078783>).
>>>> Make sure you install certmonger before running
>>>> ipa-server-install/ipa-replica-install. On F20 you can use RPMs located
>>>> at <http://jcholast.fedorapeople.org/certmonger-git/>.
>>>>
>>>> To test automatic renewal, move system time forward (see
>>>> <https://fedorahosted.org/freeipa/ticket/2803#comment:17> for more info
>>>> about certificate renewal testing, nickname of the CA certificate is
>>>> "caSigningCert cert-pki-ca"). In CA-full installs the renewal should be
>>>> fully automatic, in CA-less installs you should be alerted via
>>>> syslog to
>>>> renew the certificate using ipa-cacert-manage.
>>>>
>>>> To test manual renewal, run "ipa-cacert-manage renew". You can run
>>>> it on
>>>> any CA master. To make the renewed certificate available on other CA
>>>> masters, you must run "getcert resubmit -d /etc/pki/pki-tomcat/alias -n
>>>> 'caSigningCert cert-pki-ca'" on each of them. Note that currently you
>>>> can't change the chaining of the CA certificate.
>>>
>>> 241
>>>
>>> Not to be too anal, but would it be too outlandish to compare the
>>> Authority Key Identifier (if there is one) with the Subject Key ID to
>>> see if the cert is self-signed? Same subject then yeah, it is probably
>>> self-signed. The keys match? Definitely.
>
> Authority key identifier is not mandatory, so it's not good enough. You
> could verify the certificate's signature with its public key, but I
> haven't figured out how to do that in python-nss.
>
> Also, if someone uses the subject name of the issuer for their CA
> certificate, I think they will run into all kinds of problems anyway.

Ok.

>
>>>
>>> 242
>>>
>>> I wonder if it would be clearer to use variables instead of a raw list
>>> in the return value for these handlers: (result, message) = handler(...)
>>> rather than examining result[0], etc. That may be beyond the scope of
>>> this patch though.
>
> Yes. It would be nice if certmonger included a Python module for helper
> scripts...

Yes, but what I mean is the internal handling returns tuples of data 
with unique variable names, then plucks them out positionally.

>
>>>
>>> x509.normalize_certificate() can raise an exception, there should be a
>>> try/except around it.
>
> If there is an exception, it will be caught in the try/except block at
> the end of the script.

Well, ok.

>
>>>
>>> For an invalid cookie, please include the values seen in the environment
>>> in the error message.
>
> Added.
>
>>>
>>> 243
>>>
>>> You are going to end up with a lot of acis with the same comment value.
>>> Perhaps add the host in there as well.
>>>
>>> These are not removed when a master is deleted.
>
> I merely did the same thing as the "Add CA Certificates for renewals"
> and "Modify CA Certificates for renewals" ACIs.
>
> I agree it's suboptimal, but IMO it should be fixed in the scope of
> <https://fedorahosted.org/freeipa/ticket/3416> (the "ipa masters
> hostgroup" part).

There is a replica_cleanup() method in replication.py. I don't know why 
this couldn't be added there.

>
>>>
>>> 244
>>>
>>> There are now several different places where the caCertificate value is
>>> updated. I wonder if it's time for a function. I found it it in
>>> dsinstance.py, upload_cacert and now renew_ca_cert.
>
> I have a patch for that, but I haven't posted it yet, since there are
> some other changes in it as well.

Ok.

>
>>>
>>> 246
>>>
>>> caRenewalMaster should be checked when a replica is deleted and moved to
>>> another master. This is a good idea. I wonder if a ticket should be
>>> opened to do something similar for CRL generation.
>
> Add new patch 262 for this.
>
> +1 on doing the same for CRL generation.
>
>>>
>>> 247
>>>
>>> We've been burned by hardcoded timeouts in the past. Should this be
>>> configurable? This module doesn't currently do any logging but it might
>>> be worth spitting out a "waiting" message, at least for debugging.
>
> Added a timeout argument.

Did you forget to send this one, I didn't see an update to 247.

>
> I had logging in the code before, but I removed it when I moved the code
> to ipapython.certmonger. Silly me. Fixed.
>
>>>
>>> 249
>>>
>>> nss_init() is always scary to me since we can only have one. I didn't
>>> see anything blow up, just wondering if this should be wrapped with an
>>> is_initialized()->shutdown() at the top.
>
> Fixed (also for verify_server_cert_validity).

Ok.

>
>>>
>>> The find_cert_from_nickname() should be in a try/except in case the cert
>>> is not found for some reason.
>
> I want the exception to be propagated to the caller in such case.

Ok.

>
>>>
>>> 251
>>>
>>> The tool should provide some feedback while it's running. For the
>>> impatient (me) it takes a really long time and it's hard to know what is
>>> going on, something in between nothing and full debug output.
>
> Added some messages about what's going on.

I dpn't see an update to 251 either.

>>>
>>> The man page needs some more work too. I think some more explanation is
>>> needed and an example would probably be really helpful as well. I think
>>> particularly an example for external certs and a description of what you
>>> mean by Self-signed CA (I assume you mean IPA-provided). I don't think
>>> it really matters how many steps there are unless you are going to
>>> provide progress output.
>
> Reworded the man page a little bit.
>
>>>
>>> Got a backtrace when running as non-root:
>>>
>>> $ ipa-cacert-manage -v renew
>>> ipa.ipaserver.install.ipa_cacert_manage.CACertManage: DEBUG:   File
>>> "/usr/lib/python2.7/site-packages/ipapython/admintool.py", line 168, in
>>> execute
>>>      self.validate_options()
>>>    File
>>> "/usr/lib/python2.7/site-packages/ipaserver/install/ipa_cacert_manage.py",
>>>
>>>
>>> line 62, in validate_options
>>>      super(CACertManage, self).validate_options(needs_root=True)
>>>    File "/usr/lib/python2.7/site-packages/ipapython/admintool.py", line
>>> 189, in validate_options
>>>      raise ScriptError('Must be root to run %s' % self.command_name, 1)
>>>
>>> ipa.ipaserver.install.ipa_cacert_manage.CACertManage: DEBUG: The
>>> ipa-cacert-manage command failed, exception: ScriptError: Must be root
>>> to run ipa-cacert-manage
>>> ipa.ipaserver.install.ipa_cacert_manage.CACertManage: ERROR: Must be
>>> root to run ipa-cacert-manage
>
> That's correct, you can run it only as root, because you can't resubmit
> certmonger requests as a regular user.

Yes but one shouldn't get a traceback!

>
>>>
>>> 252
>>>
>>> In what context would this be executing? My guess is that certmonger is
>>> trying to do the renewal but a new cert hasn't been issued yet, so this
>>> gets sysloged?
>
> If you have an externally signed CA that's about to expire and the
> renewed version of it is not available in LDAP, then the message gets
> syslogged.

Ok.

>
>>>
>>> Still doing functional testing.
>>
>> My current scenario:
>>
>> 1. Newly installed IPA master with these patches.
>> 2. Replica using IPA 3.3.4 (yeah, I cheated)
>>
>> While doing time travel I had a single cert fail on the initial master
>> with this:
>>
>>          ca-error: Server at https://lyra.example.com/ipa/xml failed
>> request, will retry: 4204 (RPC failed at server.  limits exceeded for
>> this query).
>>
>> Mar 21 11:00:22 lyra ns-slapd: GSSAPI Error: Unspecified GSS failure.
>> Minor code may provide more information (Cannot contact any KDC for
>> realm 'EXAMPLE.COM')
>> Mar 21 11:00:22 lyra certmonger: 2016-03-21 11:00:22 [28676] Server at
>> https://lyra.example.com/ipa/xml failed request, will retry: 4204 (RPC
>> failed at server.  limits exceeded for this query).
>>
>>  From the access log:
>>
>> [21/Mar/2016:11:00:21 -0400] conn=49 op=5 SRCH
>> base="krbprincipalname=HTTP/lyra.example.com at EXAMPLE.COM,cn=services,cn=accounts,dc=example,dc=com"
>>
>> scope=0 filter="(objectClass=*)" attrs="userCertificate krbPrincipalName
>> * ipaKrbAuthzData managedBy aci"
>> [21/Mar/2016:11:00:21 -0400] conn=49 op=5 RESULT err=3 tag=101
>> nentries=0 etime=17
>>
>> So yeah, 17 seconds is a long time.
>>
>> A resubmit fixed it and certmonger would have done this automatically if
>> I had the patience, so not too worried about that.
>
> OK.
>
>>
>> After moving time forward on the replica these certificates are in
>> CA_WORKING:
>>
>> ipaCert
>> auditSigningCert cert-pki-ca
>> ocspSigningCert cert-pki-ca
>> subsystemCert cert-pki-ca
>>
>> cn=ca_renewal is completely empty on the replica. On the master it only
>> has the subsystemCert. I'm guessing this is at least partly due to my
>> switching time one system at a time rather than (somewhat)
>> simultaneously, but it still would have blown up with 3 missing certs.
>
> Can you post the related log messages from /var/log/messages from the
> master somewhere?
>
> There's not much I can do about broken replication. I think you hit
> <https://fedorahosted.org/389/ticket/47632>.
>
>>
>> rob
>
> Thanks for the review.
>
> Updated and rebased patches attached.
>

Patch 262 has lots of lint errors because you're adding arguments to 
functions that don't currently define one, is_renewal_master() for example.

I think the ipa-cacert-manage man page is missing one really important 
piece: why would you ever need to run this? And when?

The renewal was failing on the replica due to SELinux failures:

# ausearch -m AVC -ts recent
----
time->Mon Mar 21 11:00:05 2016
type=SYSCALL msg=audit(1458572405.859:828): arch=c000003e syscall=59 
success=no exit=-13 a0=c687c0 a1=c688c0 a2=c66e40 a3=7ffff0a46120 
items=0 ppid=4172 pid=4173 auid=4294967295 uid=0 gid=0 euid=0 suid=0 
fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="sh" 
exe="/usr/bin/bash" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1458572405.859:828): avc:  denied  { execute } for 
pid=4173 comm="sh" name="ldconfig" dev="dm-1" ino=134149 
scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:ldconfig_exec_t:s0 tclass=file
----
time->Mon Mar 21 11:00:05 2016
type=SYSCALL msg=audit(1458572405.859:829): arch=c000003e syscall=4 
success=no exit=-13 a0=c687c0 a1=7ffff0a462b0 a2=7ffff0a462b0 
a3=7ffff0a46120 items=0 ppid=4172 pid=4173 auid=4294967295 uid=0 gid=0 
euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) 
comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:certmonger_t:s0 
key=(null)
type=AVC msg=audit(1458572405.859:829): avc:  denied  { getattr } for 
pid=4173 comm="sh" path="/usr/sbin/ldconfig" dev="dm-1" ino=134149 
scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:ldconfig_exec_t:s0 tclass=file
----
time->Mon Mar 21 11:00:05 2016
type=SYSCALL msg=audit(1458572405.859:830): arch=c000003e syscall=4 
success=no exit=-13 a0=c687c0 a1=7ffff0a46290 a2=7ffff0a46290 
a3=7ffff0a46120 items=0 ppid=4172 pid=4173 auid=4294967295 uid=0 gid=0 
euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) 
comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:certmonger_t:s0 
key=(null)
type=AVC msg=audit(1458572405.859:830): avc:  denied  { getattr } for 
pid=4173 comm="sh" path="/usr/sbin/ldconfig" dev="dm-1" ino=134149 
scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:ldconfig_exec_t:s0 tclass=file
----
time->Mon Mar 21 11:00:06 2016
type=SYSCALL msg=audit(1458572406.271:831): arch=c000003e syscall=59 
success=no exit=-13 a0=24aa7c0 a1=24aa8c0 a2=24a8e40 a3=7fffbd055ac0 
items=0 ppid=4183 pid=4184 auid=4294967295 uid=0 gid=0 euid=0 suid=0 
fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="sh" 
exe="/usr/bin/bash" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1458572406.271:831): avc:  denied  { execute } for 
pid=4184 comm="sh" name="ldconfig" dev="dm-1" ino=134149 
scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:ldconfig_exec_t:s0 tclass=file
----
time->Mon Mar 21 11:00:06 2016
type=SYSCALL msg=audit(1458572406.272:832): arch=c000003e syscall=4 
success=no exit=-13 a0=24aa7c0 a1=7fffbd055c50 a2=7fffbd055c50 
a3=7fffbd055ac0 items=0 ppid=4183 pid=4184 auid=4294967295 uid=0 gid=0 
euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) 
comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:certmonger_t:s0 
key=(null)
type=AVC msg=audit(1458572406.272:832): avc:  denied  { getattr } for 
pid=4184 comm="sh" path="/usr/sbin/ldconfig" dev="dm-1" ino=134149 
scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:ldconfig_exec_t:s0 tclass=file
----
time->Mon Mar 21 11:00:06 2016
type=SYSCALL msg=audit(1458572406.272:833): arch=c000003e syscall=4 
success=no exit=-13 a0=24aa7c0 a1=7fffbd055c30 a2=7fffbd055c30 
a3=7fffbd055ac0 items=0 ppid=4183 pid=4184 auid=4294967295 uid=0 gid=0 
euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) 
comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:certmonger_t:s0 
key=(null)
type=AVC msg=audit(1458572406.272:833): avc:  denied  { getattr } for 
pid=4184 comm="sh" path="/usr/sbin/ldconfig" dev="dm-1" ino=134149 
scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:ldconfig_exec_t:s0 tclass=file
----
time->Mon Mar 21 11:00:06 2016
type=SYSCALL msg=audit(1458572406.334:834): arch=c000003e syscall=2 
success=no exit=-13 a0=315f900 a1=0 a2=1b6 a3=7fffbfef2060 items=0 
ppid=3672 pid=4168 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 
egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="dogtag-ipa-ca-r" 
exe="/usr/bin/python2.7" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1458572406.334:834): avc:  denied  { read } for 
pid=4168 comm="dogtag-ipa-ca-r" name="sysupgrade.state" dev="dm-1" 
ino=276510 scontext=system_u:system_r:certmonger_t:s0 
tcontext=unconfined_u:object_r:var_lib_t:s0 tclass=file
----
time->Mon Mar 21 11:00:07 2016
type=SYSCALL msg=audit(1458572407.378:835): arch=c000003e syscall=2 
success=no exit=-13 a0=2c98030 a1=0 a2=1b6 a3=7fffbfef2450 items=0 
ppid=3672 pid=4168 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 
egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="dogtag-ipa-ca-r" 
exe="/usr/bin/python2.7" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1458572407.378:835): avc:  denied  { read } for 
pid=4168 comm="dogtag-ipa-ca-r" name="sysrestore.state" dev="dm-1" 
ino=273976 scontext=system_u:system_r:certmonger_t:s0 
tcontext=unconfined_u:object_r:var_lib_t:s0 tclass=file
----
time->Mon Mar 21 11:00:07 2016
type=SYSCALL msg=audit(1458572407.385:836): arch=c000003e syscall=42 
success=no exit=-13 a0=4 a1=7fffbfef24f0 a2=6e a3=7fffbfef24f2 items=0 
ppid=3672 pid=4168 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 
egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="dogtag-ipa-ca-r" 
exe="/usr/bin/python2.7" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1458572407.385:836): avc:  denied  { write } for 
pid=4168 comm="dogtag-ipa-ca-r" name="slapd-GREYOAK-COM.socket" 
dev="tmpfs" ino=53896 scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:dirsrv_var_run_t:s0 tclass=sock_file
----
time->Mon Mar 21 11:00:07 2016
type=SYSCALL msg=audit(1458572407.385:837): arch=c000003e syscall=42 
success=no exit=-13 a0=4 a1=7fffbfef2a80 a2=23 a3=0 items=0 ppid=3672 
pid=4168 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 
fsgid=0 ses=4294967295 tty=(none) comm="dogtag-ipa-ca-r" 
exe="/usr/bin/python2.7" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1458572407.385:837): avc:  denied  { write } for 
pid=4168 comm="dogtag-ipa-ca-r" name="slapd-GREYOAK-COM.socket" 
dev="tmpfs" ino=53896 scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:dirsrv_var_run_t:s0 tclass=sock_file
----
time->Mon Mar 21 11:06:58 2016
type=SYSCALL msg=audit(1458572818.975:851): arch=c000003e syscall=59 
success=no exit=-13 a0=21807c0 a1=21808c0 a2=217ee40 a3=7fff9d88d0a0 
items=0 ppid=4338 pid=4339 auid=4294967295 uid=0 gid=0 euid=0 suid=0 
fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="sh" 
exe="/usr/bin/bash" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1458572818.975:851): avc:  denied  { execute } for 
pid=4339 comm="sh" name="ldconfig" dev="dm-1" ino=134149 
scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:ldconfig_exec_t:s0 tclass=file
----
time->Mon Mar 21 11:06:58 2016
type=SYSCALL msg=audit(1458572818.975:852): arch=c000003e syscall=4 
success=no exit=-13 a0=21807c0 a1=7fff9d88d230 a2=7fff9d88d230 
a3=7fff9d88d0a0 items=0 ppid=4338 pid=4339 auid=4294967295 uid=0 gid=0 
euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) 
comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:certmonger_t:s0 
key=(null)
type=AVC msg=audit(1458572818.975:852): avc:  denied  { getattr } for 
pid=4339 comm="sh" path="/usr/sbin/ldconfig" dev="dm-1" ino=134149 
scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:ldconfig_exec_t:s0 tclass=file
----
time->Mon Mar 21 11:06:58 2016
type=SYSCALL msg=audit(1458572818.975:853): arch=c000003e syscall=4 
success=no exit=-13 a0=21807c0 a1=7fff9d88d210 a2=7fff9d88d210 
a3=7fff9d88d0a0 items=0 ppid=4338 pid=4339 auid=4294967295 uid=0 gid=0 
euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) 
comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:certmonger_t:s0 
key=(null)
type=AVC msg=audit(1458572818.975:853): avc:  denied  { getattr } for 
pid=4339 comm="sh" path="/usr/sbin/ldconfig" dev="dm-1" ino=134149 
scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:ldconfig_exec_t:s0 tclass=file
----
time->Mon Mar 21 11:06:59 2016
type=SYSCALL msg=audit(1458572819.001:854): arch=c000003e syscall=59 
success=no exit=-13 a0=1b5b7c0 a1=1b5b8c0 a2=1b59e40 a3=7fff7a364d20 
items=0 ppid=4348 pid=4349 auid=4294967295 uid=0 gid=0 euid=0 suid=0 
fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="sh" 
exe="/usr/bin/bash" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1458572819.001:854): avc:  denied  { execute } for 
pid=4349 comm="sh" name="ldconfig" dev="dm-1" ino=134149 
scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:ldconfig_exec_t:s0 tclass=file
----
time->Mon Mar 21 11:06:59 2016
type=SYSCALL msg=audit(1458572819.001:855): arch=c000003e syscall=4 
success=no exit=-13 a0=1b5b7c0 a1=7fff7a364eb0 a2=7fff7a364eb0 
a3=7fff7a364d20 items=0 ppid=4348 pid=4349 auid=4294967295 uid=0 gid=0 
euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) 
comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:certmonger_t:s0 
key=(null)
type=AVC msg=audit(1458572819.001:855): avc:  denied  { getattr } for 
pid=4349 comm="sh" path="/usr/sbin/ldconfig" dev="dm-1" ino=134149 
scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:ldconfig_exec_t:s0 tclass=file
----
time->Mon Mar 21 11:06:59 2016
type=SYSCALL msg=audit(1458572819.001:856): arch=c000003e syscall=4 
success=no exit=-13 a0=1b5b7c0 a1=7fff7a364e90 a2=7fff7a364e90 
a3=7fff7a364d20 items=0 ppid=4348 pid=4349 auid=4294967295 uid=0 gid=0 
euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) 
comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:certmonger_t:s0 
key=(null)
type=AVC msg=audit(1458572819.001:856): avc:  denied  { getattr } for 
pid=4349 comm="sh" path="/usr/sbin/ldconfig" dev="dm-1" ino=134149 
scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:ldconfig_exec_t:s0 tclass=file
----
time->Mon Mar 21 11:06:59 2016
type=SYSCALL msg=audit(1458572819.032:857): arch=c000003e syscall=2 
success=no exit=-13 a0=2630900 a1=0 a2=1b6 a3=7fff361b7be0 items=0 
ppid=3672 pid=4337 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 
egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="dogtag-ipa-ca-r" 
exe="/usr/bin/python2.7" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1458572819.032:857): avc:  denied  { read } for 
pid=4337 comm="dogtag-ipa-ca-r" name="sysupgrade.state" dev="dm-1" 
ino=276510 scontext=system_u:system_r:certmonger_t:s0 
tcontext=unconfined_u:object_r:var_lib_t:s0 tclass=file
----
time->Mon Mar 21 11:06:59 2016
type=SYSCALL msg=audit(1458572819.998:858): arch=c000003e syscall=2 
success=no exit=-13 a0=26bdcc0 a1=0 a2=1b6 a3=7fff361b7fd0 items=0 
ppid=3672 pid=4337 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 
egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="dogtag-ipa-ca-r" 
exe="/usr/bin/python2.7" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1458572819.998:858): avc:  denied  { read } for 
pid=4337 comm="dogtag-ipa-ca-r" name="sysrestore.state" dev="dm-1" 
ino=273976 scontext=system_u:system_r:certmonger_t:s0 
tcontext=unconfined_u:object_r:var_lib_t:s0 tclass=file
----
time->Mon Mar 21 11:06:59 2016
type=SYSCALL msg=audit(1458572819.999:859): arch=c000003e syscall=42 
success=no exit=-13 a0=4 a1=7fff361b8070 a2=6e a3=7fff361b8072 items=0 
ppid=3672 pid=4337 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 
egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="dogtag-ipa-ca-r" 
exe="/usr/bin/python2.7" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1458572819.999:859): avc:  denied  { write } for 
pid=4337 comm="dogtag-ipa-ca-r" name="slapd-GREYOAK-COM.socket" 
dev="tmpfs" ino=57178 scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:dirsrv_var_run_t:s0 tclass=sock_file
----
time->Mon Mar 21 11:06:59 2016
type=SYSCALL msg=audit(1458572819.999:860): arch=c000003e syscall=42 
success=no exit=-13 a0=4 a1=7fff361b8600 a2=23 a3=0 items=0 ppid=3672 
pid=4337 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 
fsgid=0 ses=4294967295 tty=(none) comm="dogtag-ipa-ca-r" 
exe="/usr/bin/python2.7" subj=system_u:system_r:certmonger_t:s0 key=(null)
type=AVC msg=audit(1458572819.999:860): avc:  denied  { write } for 
pid=4337 comm="dogtag-ipa-ca-r" name="slapd-GREYOAK-COM.socket" 
dev="tmpfs" ino=57178 scontext=system_u:system_r:certmonger_t:s0 
tcontext=system_u:object_r:dirsrv_var_run_t:s0 tclass=sock_file

Mar 21 11:07:00 sif.greyoak.com dogtag-ipa-ca-renew-agent-submit[4337]: 
Traceback (most recent call last):
File "/usr/libexec/certmonger/dogtag-ipa-ca-renew-agent-submit", line 
299, in <module>
sys.exit(main())
File "/usr/libexec/certmonger/dogtag-ipa-ca-renew-agent-submit", line 
288, in main
if ca.is_renewal_master():
File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", 
line 1548, in is_renewal_master
self.ldap_connect()
File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", 
line 118, in ldap_connect
conn.do_external_bind(pw_name)
File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1727, 
in do_external_bind
self.conn.sasl_interactive_bind_s, timeout, None, auth_tokens)
File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1713, 
in __bind_with_wait
self.__wait_for_connection(timeout)
File "/usr/lib/python2.7/site-packages/ipapython/ipaldap.py", line 1699, 
in __wait_for_connection
wait_for_open_socket(lurl.hostport, timeout)
File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 1173, 
in wait_for_open_socket
raise e
error: [Errno 13] Permission denied
Mar 21 11:07:00 sif.greyoak.com certmonger[3672]: 2016-03-21 11:07:00 
[3672] Internal error

I updated selinux-policy but I'm not seeing the certs added consistently 
to ca_renewal so there is nothing to do, so it sits in CA_WORKING. I 
verified it isn't a replication issue, the replication is working fine, 
the certs just weren't pushed.

Here is what syslog on the initial master has to say about it. The 
reason strange part is the references to dogtag-ipa-renew-agent:

Mar 21 11:00:00 lyra systemd: Time has been changed
Mar 21 11:01:01 lyra systemd: Starting Session 323 of user root.
Mar 21 11:01:01 lyra systemd: Started Session 323 of user root.
Mar 21 11:02:13 lyra ntpd[6652]: 0.0.0.0 0618 08 no_sys_peer
Mar 21 11:03:06 lyra certmonger: Certificate named "auditSigningCert 
cert-pki-ca" in token "NSS Certificate DB" in database 
"/etc/pki/pki-tomcat/alias" will not be valid after 20160330184642.
Mar 21 11:03:06 lyra certmonger: Certificate named "ocspSigningCert 
cert-pki-ca" in token "NSS Certificate DB" in database 
"/etc/pki/pki-tomcat/alias" will not be valid after 20160330184640.
Mar 21 11:03:06 lyra certmonger: Certificate named "subsystemCert 
cert-pki-ca" in token "NSS Certificate DB" in database 
"/etc/pki/pki-tomcat/alias" will not be valid after 20160330184641.
Mar 21 11:03:06 lyra certmonger: Certificate named "ipaCert" in token 
"NSS Certificate DB" in database "/etc/httpd/alias" will not be valid 
after 20160330184711.
Mar 21 11:03:06 lyra certmonger: Certificate named "Server-Cert 
cert-pki-ca" in token "NSS Certificate DB" in database 
"/etc/pki/pki-tomcat/alias" will not be valid after 20160330184641.
Mar 21 11:03:06 lyra certmonger: Certificate named "Server-Cert" in 
token "NSS Certificate DB" in database "/etc/dirsrv/slapd-GREYOAK-COM" 
will not be valid after 20160410184720.
Mar 21 11:03:06 lyra certmonger: Certificate named "Server-Cert" in 
token "NSS Certificate DB" in database "/etc/httpd/alias" will not be 
valid after 20160410184810.
Mar 21 11:03:11 lyra certmonger: Certificate named "Server-Cert 
cert-pki-ca" in token "NSS Certificate DB" in database 
"/etc/pki/pki-tomcat/alias" issued by CA and saved.
Mar 21 11:03:15 lyra dogtag-ipa-ca-renew-agent-submit: Forwarding 
request to dogtag-ipa-renew-agent
Mar 21 11:03:15 lyra dogtag-ipa-ca-renew-agent-submit: Forwarding 
request to dogtag-ipa-renew-agent
Mar 21 11:03:15 lyra dogtag-ipa-ca-renew-agent-submit: Forwarding 
request to dogtag-ipa-renew-agent
Mar 21 11:03:15 lyra dogtag-ipa-ca-renew-agent-submit: Forwarding 
request to dogtag-ipa-renew-agent
Mar 21 11:03:17 lyra dogtag-ipa-ca-renew-agent-submit: 
dogtag-ipa-renew-agent returned 5
Mar 21 11:03:17 lyra dogtag-ipa-ca-renew-agent-submit: 
dogtag-ipa-renew-agent returned 5
Mar 21 11:03:17 lyra dogtag-ipa-ca-renew-agent-submit: 
dogtag-ipa-renew-agent returned 5
Mar 21 11:03:18 lyra dogtag-ipa-ca-renew-agent-submit: 
dogtag-ipa-renew-agent returned 5
Mar 21 11:03:19 lyra restart_httpd: certmonger restarted httpd
Mar 21 11:03:19 lyra systemd: Stopping The Apache HTTP Server...
Mar 21 11:03:21 lyra systemd: Starting The Apache HTTP Server...
Mar 21 11:03:22 lyra systemd: Started The Apache HTTP Server.
Mar 21 11:03:22 lyra certmonger: Certificate named "Server-Cert" in 
token "NSS Certificate DB" in database "/etc/httpd/alias" issued by CA 
and saved.
Mar 21 11:03:29 lyra dogtag-ipa-ca-renew-agent-submit: Forwarding 
request to dogtag-ipa-renew-agent
Mar 21 11:03:29 lyra dogtag-ipa-ca-renew-agent-submit: Forwarding 
request to dogtag-ipa-renew-agent
Mar 21 11:03:29 lyra dogtag-ipa-ca-renew-agent-submit: Forwarding 
request to dogtag-ipa-renew-agent
Mar 21 11:03:29 lyra dogtag-ipa-ca-renew-agent-submit: Forwarding 
request to dogtag-ipa-renew-agent
Mar 21 11:03:31 lyra restart_dirsrv: certmonger restarted dirsrv 
instance 'GREYOAK-COM'
Mar 21 11:03:31 lyra systemd: Reloading.
Mar 21 11:03:31 lyra systemd: Stopping 389 Directory Server GREYOAK-COM....
Mar 21 11:03:33 lyra dogtag-ipa-ca-renew-agent-submit: 
dogtag-ipa-renew-agent returned 2
Mar 21 11:03:33 lyra dogtag-ipa-ca-renew-agent-submit: 
dogtag-ipa-renew-agent returned 2
Mar 21 11:03:33 lyra dogtag-ipa-ca-renew-agent-submit: 
dogtag-ipa-renew-agent returned 2
Mar 21 11:03:33 lyra dogtag-ipa-ca-renew-agent-submit: 
dogtag-ipa-renew-agent returned 2
Mar 21 11:03:33 lyra certmonger: 2016-03-21 11:03:33 [8438] Server at 
"https://lyra.greyoak.com:8443/ca/agent/ca/profileProcess" replied: 1: 
Invalid Credential.
Mar 21 11:03:33 lyra certmonger: 2016-03-21 11:03:33 [8438] Server at 
"https://lyra.greyoak.com:8443/ca/agent/ca/profileProcess" replied: 1: 
Invalid Credential.
Mar 21 11:03:33 lyra certmonger: 2016-03-21 11:03:33 [8438] Server at 
"https://lyra.greyoak.com:8443/ca/agent/ca/profileProcess" replied: 1: 
Invalid Credential.
Mar 21 11:03:33 lyra certmonger: 2016-03-21 11:03:33 [8438] Server at 
"https://lyra.greyoak.com:8443/ca/agent/ca/profileProcess" replied: 1: 
Invalid Credential.
Mar 21 11:03:33 lyra systemd: Starting 389 Directory Server GREYOAK-COM....
Mar 21 11:03:34 lyra systemd: Started 389 Directory Server GREYOAK-COM..
Mar 21 11:03:34 lyra ns-slapd: GSSAPI Error: Unspecified GSS failure. 
Minor code may provide more information (No Kerberos credentials available)
Mar 21 11:03:35 lyra certmonger: Certificate named "Server-Cert" in 
token "NSS Certificate DB" in database "/etc/dirsrv/slapd-GREYOAK-COM" 
issued by CA and saved.




More information about the Freeipa-devel mailing list