[Freeipa-users] ipa-replica-prepare Certificate issuance failed

[Chris Evich]

On 05/04/2012 03:18 PM, Rob Crittenden wrote:
> Chris Evich wrote:
>> Hi,
>>
>> I've got a FreeIPA setup at home I just built the other week on Fedora
>> 16. It's a very small/basic setup I'm mainly using for secure
>> NFS+Kerberos and automount. Today, I updated everything and rebooted,
...cut...
>> [04/May/2012:14:44:09][http-9444-1]: CMSServlet: curDate=Fri May 04
>> 14:44:09 EDT 2012 id=caProfileSubmitSSLClient time=11
>>
>> Which also looks normal (to me). Though I've done nothing intentional
>> with anything certificate related, again this is mainly a setup for
>> kerberos. Where else can I look, or what can I run to get more clues why
>> ipa-replica-prepare is failing?
>
> I think we'll need to get more info out of dogtag. If you edit
> /etc/ipa/default.conf and add debug=True, restart httpd, re-run the
> replica-prepare, there should be more information on the failure in
> /var/log/httpd/error_log.
>
> rob

Whoa, okay, a WHOLE lot more info.:

[Fri May 04 15:43:19 2012] [notice] Apache/2.2.22 (Unix) DAV/2 
mod_auth_kerb/5.4 mod_nss/2.2.17 NSS/3.12.9.0 mod_wsgi/3.3 Python/2.7.2 
configured -- resuming normal operations
[Fri May 04 15:43:22 2012] [error] ipa: DEBUG: importing all plugin 
modules in '/usr/lib/python2.7/site-packages/ipalib/plugins'...
[Fri May 04 15:43:22 2012] [error] ipa: DEBUG: importing plugin module 
'/usr/lib/python2.7/site-packages/ipalib/plugins/aci.py'
...lots more import plugin messages...
[Fri May 04 15:43:24 2012] [error] ipa: DEBUG: Mounting 
ipaserver.rpcserver.xmlserver() at 'xml'
[Fri May 04 15:43:24 2012] [error] ipa: DEBUG: Mounting 
ipaserver.rpcserver.jsonserver() at 'json'
[Fri May 04 15:43:25 2012] [error] ipa: DEBUG: Mounting 
ipaserver.rpcserver.xmlserver() at 'xml'
[Fri May 04 15:43:25 2012] [error] ipa: DEBUG: Mounting 
ipaserver.rpcserver.jsonserver() at 'json'
[Fri May 04 15:43:28 2012] [error] ipa: INFO: *** PROCESS START ***
[Fri May 04 15:43:28 2012] [error] ipa: INFO: *** PROCESS START ***

Then I run ipa-replica-prepare <fqdn of replica>, put in my Directory 
Manager password, and it outputs the same "Certificate issuance failed". 
  I had a tailf on /var/log/httpd/error_log but nothing new was logged 
(nothing logged at all in fact) :S

In /var/log/pki-ca/debug I see (what appears similar to before):

[04/May/2012:15:46:31][Timer-0]: In LdapBoundConnFactory::getConn()
[04/May/2012:15:46:31][Timer-0]: masterConn is connected: true
[04/May/2012:15:46:31][Timer-0]: getConn: conn is connected true
[04/May/2012:15:46:31][Timer-0]: getConn: mNumConns now 2
[04/May/2012:15:46:31][Timer-0]: SecurityDomainSessionTable: 
getSessionIds():  no sessions have been created
[04/May/2012:15:46:31][Timer-0]: returnConn: mNumConns now 3
[04/May/2012:15:48:11][http-9444-1]: CMSServlet:service() uri = 
/ca/ee/ca/profileSubmitSSLClient
[04/May/2012:15:48:11][http-9444-1]: CMSServlet::service() param 
name='cert_request_type' value='pkcs10'
[04/May/2012:15:48:11][http-9444-1]: CMSServlet::service() param 
name='cert_request' 
value='MIICcjCCAVoCAQAwLTESMBAGA1UEChMJWUVXRVNTLlVTMRcwFQYDVQQDEw5raW5n
...cut...
vAUbEmg/
'
[04/May/2012:15:48:11][http-9444-1]: CMSServlet::service() param 
name='requestor_name' value='IPA Installer'
[04/May/2012:15:48:11][http-9444-1]: CMSServlet::service() param 
name='xmlOutput' value='true'
[04/May/2012:15:48:11][http-9444-1]: CMSServlet::service() param 
name='profileId' value='caIPAserviceCert'
[04/May/2012:15:48:11][http-9444-1]: CMSServlet: 
caProfileSubmitSSLClient start to service.
[04/May/2012:15:48:11][http-9444-1]: xmlOutput true
[04/May/2012:15:48:11][http-9444-1]: Start of ProfileSubmitServlet Input 
Parameters
[04/May/2012:15:48:11][http-9444-1]: ProfileSubmitServlet Input 
Parameter cert_request_type='pkcs10'
[04/May/2012:15:48:11][http-9444-1]: ProfileSubmitServlet Input 
Parameter 
cert_request='MIICcjCCAVoCAQAwLTESMBAGA1UEChMJWUVXRVNTLlVTMRcwFQYDVQQDEw5raW5n
...cut...
vAUbEmg/
'
[04/May/2012:15:48:11][http-9444-1]: ProfileSubmitServlet Input 
Parameter requestor_name='IPA Installer'
[04/May/2012:15:48:11][http-9444-1]: ProfileSubmitServlet Input 
Parameter xmlOutput='true'
[04/May/2012:15:48:11][http-9444-1]: ProfileSubmitServlet Input 
Parameter profileId='caIPAserviceCert'
[04/May/2012:15:48:11][http-9444-1]: End of ProfileSubmitServlet Input 
Parameters
[04/May/2012:15:48:11][http-9444-1]: ProfileSubmitServlet: start serving
[04/May/2012:15:48:11][http-9444-1]: ProfileSubmitServlet: SubId=profile
[04/May/2012:15:48:11][http-9444-1]: ProfileSubmitServlet: isRenewal false
[04/May/2012:15:48:11][http-9444-1]: ProfileSubmitServlet: profileId 
caIPAserviceCert
[04/May/2012:15:48:11][http-9444-1]: CMSServlet: curDate=Fri May 04 
15:48:11 EDT 2012 id=caProfileSubmitSSLClient time=9

I think the 3-minute time difference is expected - I was checking 
through other logs.  Nothing that appears relevant shows up in 
audit.log, messages, http/access.log, dirsrv/slapd-PKI-IPA/errors or access:

[04/May/2012:15:46:30 -0400] conn=2 op=58 SRCH 
base="ou=sessions,ou=Security Domain,o=ipaca" scope=2 
filter="(objectClass=securityDomainSessionEntry)" attrs="cn"
[04/May/2012:15:46:30 -0400] conn=2 op=58 RESULT err=32 tag=101 
nentries=0 etime=0

The only thing I've noticed recently (maybe after the kernel updated 
today) is every few minutes:

May  4 15:43:57 <master> ntpd[889]: frequency error -898 PPM exceeds 
tolerance 500 PPM
May  4 15:50:01 <master> ntpd[889]: frequency error -1475 PPM exceeds 
tolerance 500 PPM
May  4 15:53:13 <master> ntpd[889]: frequency error -1012 PPM exceeds 
tolerance 500 PPM

Though I don't notice (with my eyes) the clock jumping around, and NTP 
is "locked" in on a few public servers.  However I understand those 
messages indicate local clock instability and know this certificate 
stuff is time-sensitive.

Also, in case it's relevant, this is a really small box: A dual-core 
Intel Atom w/ 2gig of memory.  Though again, I've got only a handful of 
hosts setup to use it and am not seeing other signs of problems: i.e. 
the IPA Web UI appears to work fine, kerberos, NFS and automount are all 
also working fine.

I'm stumped.  Where to look next?