[Freeipa-users] Failure decoding Certificate Signing Request

Thu Oct 24 01:58:13 UTC 2013

Thomson, Ryan wrote:
>> -----Original Message-----
>> From: Rob Crittenden [mailto:rcritten at redhat.com]
>> Sent: Tuesday, October 22, 2013 7:13 PM
>> To: Thomson, Ryan; freeipa-users at redhat.com
>> Subject: Re: [Freeipa-users] Failure decoding Certificate Signing Request
>>
>> Thomson, Ryan wrote:
>>>> -----Original Message-----
>>>> From: Rob Crittenden [mailto:rcritten at redhat.com]
>>>> Sent: Tuesday, October 22, 2013 10:46 AM
>>>> To: Thomson, Ryan; freeipa-users at redhat.com
>>>> Subject: Re: [Freeipa-users] Failure decoding Certificate Signing
>>>> Request
>>>>
>>>> Thomson, Ryan wrote:
>>>>> Hi Rob,
>>>>>
>>>>>> There is some duplication in the error strings (ticket
>>>>>> https://fedorahosted.org/freeipa/ticket/3988). Did you add a number
>>>>>> prefix to yours, I see a 3 -in the error. If so, by my calculation,
>>>>>> this works out to be an NSPRError. It would be helpful to know what
>>>>>> exception is being raised, which we don't do.
>>>>>
>>>>> I did prefix numbers to the various error strings.
>>>>>
>>>>>> Either way, if you could enhance each occurrence of 'Failure
>>>>>> decoding Certificate Signing Request' in /usr/lib/python*/site-
>>>>>> packages/ipalib/plugins/cert.py to something like:
>>>>>>
>>>>>> except NSPEError, nsprerr:
>>>>>>         raise  errors.CertificateOperationError(error=_('Failure
>>>>>> decoding Certificate Signing Request" %s') % nsprerr)
>>>>>>
>>>>>> You'll need to restart the httpd process afterwards. This should
>>>>>> give us the real reason for the failure.
>>>>>
>>>>> Done. The error I get now is:
>>>>>
>>>>> Server failed request, will retry: 4301 (RPC failed at server.
>>>>> Certificate
>>>> operation cannot be completed: Failure decoding Certificate Signing
>>>> Request" [Errno -8018] error (-8018) unknown).
>>>>
>>>> Hmm, very strange indeed.
>>>>
>>>> It should be using the NSS database initialized in mod_nss for
>>>> Apache, which should remain open and available for wsgi. It almost
>>>> seems like the database has been shut down.
>>>>
>>>> Can you add a logging event to log the value of nss.nss_is_initialized()?
>>>>
>>>> Have you done any configuration customization in Apache or mod_nss?
>>>>
>>>> thanks
>>>>
>>>> rob
>>>
>>> The return value of nss.nss_is_initialized() is False when I resubmit the
>> (expired) certs through certmonger.
>>
>> Ok, that is the core of the issue then. pkcs10.load_certificate() will initialize
>> NSS If it isn't already and I'm guessing that is failing and is the source of this
>> exception.
>>
>>> I did have a custom config for apache that configured a virtual host with
>> SSL. I have disabled that config and restarted httpd, resubmitted the certs to
>> certmonger but I still receive the same error. I will continue poking through
>> my apache / mod_nss config to see if anything stands out.
>>
>> You're still using mod_nss though, right?
>>
>> rob
>
> I'm still using mod_nss.
>
> I have discovered that I might be focusing on a symptom here rather than the core problem. If I restart httpd and then certmonger, the first error returned when certmonger tries to renew the certificates is not "Failure decoding Certificate Signing Request" but rather:
>
> "Server failed request, will retry: 4301 (RPC failed at server.  Certificate operation cannot be completed: EXCEPTION (You did not provide a valid certificate for this operation))."
>
> for two certs, and:
>
> "Server failed request, will retry: 907 (RPC failed at server.  cannot connect to 'https://HOSTNAME.DOMAIN:443/ca/agent/ca/displayBySerial': [Errno -8053] (SEC_ERROR_BUSY) NSS could not shutdown. Objects are still in use.)."
>
> for a third.
>
> After some time, I resubmit and the error returned changes to "Failure decoding..." for all three (expired) certs.
>
> In the httpd error_log during that time, I see the following errors and traceback:
>
> [Sun Oct 06 21:13:14 2013] [error] /usr/lib64/python2.6/getpass.py:83: GetPassWarning: Can not control echo on the terminal.
> [Sun Oct 06 21:13:14 2013] [error]   passwd = fallback_getpass(prompt, stream)
> [Sun Oct 06 21:13:14 2013] [error] Warning: Password input may be echoed.
> [Sun Oct 06 21:13:14 2013] [error] Enter password for internal:
> [Sun Oct 06 21:13:14 2013] [error] exception in PK11 password callback
> [Sun Oct 06 21:13:14 2013] [error] Traceback (most recent call last):
> [Sun Oct 06 21:13:14 2013] [error]   File "/usr/lib/python2.6/site-packages/ipapython/nsslib.py", line 229, in password_callback
> [Sun Oct 06 21:13:14 2013] [error]     return getpass.getpass("Enter password for %s: " % slot.token_name);
> [Sun Oct 06 21:13:14 2013] [error]   File "/usr/lib64/python2.6/getpass.py", line 83, in unix_getpass
> [Sun Oct 06 21:13:14 2013] [error]     passwd = fallback_getpass(prompt, stream)
> [Sun Oct 06 21:13:14 2013] [error]   File "/usr/lib64/python2.6/getpass.py", line 118, in fallback_getpass
> [Sun Oct 06 21:13:14 2013] [error]     return _raw_input(prompt, stream)
> [Sun Oct 06 21:13:14 2013] [error]   File "/usr/lib64/python2.6/getpass.py", line 135, in _raw_input
> [Sun Oct 06 21:13:14 2013] [error]     raise EOFError
> [Sun Oct 06 21:13:14 2013] [error] EOFError
>
> It looks like perhaps there is a problem retrieving a password (for an NSS db?) with getpass.
>
> Thanks for your help so far, Rob. Much appreciated.

I think this still points to NSS not being initialized. The way we 
currently use NSS in the server is Apache fires things up using mod_nss, 
then because we are a child of Apache via mod_wsgi, we inherit the open 
NSS database in /etc/httpd/alias. This gives us the CA cert and the 
client cert we need in order to talk to dogtag.

What I thought, and the excellent debugging above confirms, is that at 
some point the NSS database is being shut down. At some point we need to 
do some crypto and try to initialize it ourselves to no avail. We 
shouldn't ever need to do it in the server and thus don't have access to 
PINs and such because we don't need them. We do initialize things from 
time to time on the client side but we tend to do a database-less 
initialization (nss_init_nodb()).

I'm not really sure what this tells us though. It would appear that SSL 
is working in Apache, because you are able to get far enough to make a 
request and have it fail. So the NSS database is still initialized in 
Apache, but for some reason the wsgi code doesn't seem to agree.

Would it be possible for you to stop and restart Apache and run some 
simple IPA command like ipa user-show admin (and let me know if it 
succeeds)? Then send me the error_log?

If you are in SELinux enforcing mode it would also be helpful to check 
for any AVCs. Maybe we simply can't access the database.

thanks

rob