Adding new replica with CA fails.

Monday, 6 July 2020

Hi all,

I'm having an issue creating a new replica with CA.
The Directory Service installation works fine but adding the CA clone
fails with a java.lang.NumberFormatException when getting the serial
number range.

This is the error logged in /var/log/pki/pki-tomcat/ca/debug:
######
...
[20/Jun/2020:15:09:55][localhost-startStop-1]: DBSubsystem: retrieving
ou=ca, ou=requests,o=ipaca
[20/Jun/2020:15:09:55][localhost-startStop-1]: DBSubsystem: updating
nextRange from 80000001 to 90000001
[20/Jun/2020:15:09:55][localhost-startStop-1]: DBSubsystem: adding new
range object: cn=80000001,ou=requests, ou=ranges,o=ipaca
[20/Jun/2020:15:09:55][localhost-startStop-1]: DBSubsystem:
getNextRange  Next range has been added: 80000001 - 90000000
[20/Jun/2020:15:09:55][localhost-startStop-1]: Releasing ldap connection
[20/Jun/2020:15:09:55][localhost-startStop-1]: returnConn: mNumConns now 3
[20/Jun/2020:15:09:55][localhost-startStop-1]: Repository: next range: 80000001
[20/Jun/2020:15:09:55][localhost-startStop-1]: Repository: Next min
serial number: 80000001
[20/Jun/2020:15:09:55][localhost-startStop-1]: DBSubsystem: Setting
next min requests number: 80000001
[20/Jun/2020:15:09:55][localhost-startStop-1]: DBSubsystem: Setting
next max requests number: 90000000
[20/Jun/2020:15:09:55][localhost-startStop-1]: Checking for a range conflict
[20/Jun/2020:15:09:55][localhost-startStop-1]: In
LdapBoundConnFactory::getConn()
[20/Jun/2020:15:09:55][localhost-startStop-1]: masterConn is connected: true
[20/Jun/2020:15:09:55][localhost-startStop-1]: getConn: conn is connected true
[20/Jun/2020:15:09:55][localhost-startStop-1]: getConn: mNumConns now 2
[20/Jun/2020:15:09:55][localhost-startStop-1]: Releasing ldap connection
[20/Jun/2020:15:09:55][localhost-startStop-1]: returnConn: mNumConns now 3
[20/Jun/2020:15:09:55][localhost-startStop-1]: CMSEngine: checking
certificate serial number ranges
[20/Jun/2020:15:09:55][localhost-startStop-1]: Repository: Serial
numbers left in range: 65536
[20/Jun/2020:15:09:55][localhost-startStop-1]: Repository: Last serial
number: 2415656960
[20/Jun/2020:15:09:55][localhost-startStop-1]: Repository: Serial
numbers available: 65536
[20/Jun/2020:15:09:55][localhost-startStop-1]: Repository: Low water
mark: 33554432
[20/Jun/2020:15:09:55][localhost-startStop-1]: Repository: Requesting next range
[20/Jun/2020:15:09:55][localhost-startStop-1]: In
LdapBoundConnFactory::getConn()
[20/Jun/2020:15:09:55][localhost-startStop-1]: masterConn is connected: true
[20/Jun/2020:15:09:55][localhost-startStop-1]: getConn: conn is connected true
[20/Jun/2020:15:09:55][localhost-startStop-1]: getConn: mNumConns now 2
[20/Jun/2020:15:09:55][localhost-startStop-1]: DBSubsystem: retrieving
ou=certificateRepository, ou=ca,o=ipaca
java.lang.NumberFormatException: For input string: "e0000001"
        at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)
        at java.lang.Integer.parseInt(Integer.java:580)
        at java.math.BigInteger.<init>(BigInteger.java:470)
        at java.math.BigInteger.<init>(BigInteger.java:606)
        at com.netscape.cmscore.dbs.DBSubsystem.getNextRange(DBSubsystem.java:417)
        at com.netscape.cmscore.dbs.Repository.checkRanges(Repository.java:546)
        at com.netscape.cmscore.apps.CMSEngine.startup(CMSEngine.java:1268)
        at com.netscape.certsrv.apps.CMS.startup(CMS.java:204)
        at com.netscape.certsrv.apps.CMS.start(CMS.java:1459)
        at com.netscape.cms.servlet.base.CMSStartServlet.init(CMSStartServlet.java:117)
        at javax.servlet.GenericServlet.init(GenericServlet.java:158)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:288)
        at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:285)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
        at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:320)
...
######

This is logged in /var/log/pki/pki-ca-spawn.20200620150752.log:
######
...
2020-06-20 15:09:47 pkispawn    : INFO     ....... executing
'systemctl stop pki-tomcatd(a)pki-tomcat.service&#39;
2020-06-20 15:09:48 pkispawn    : INFO     ....... removing temp SSL
server cert from internal token: Server-Cert cert-pki-ca
2020-06-20 15:09:48 pki.nssdb   : DEBUG    Command: certutil -D -d
/var/lib/pki/pki-tomcat/alias -f /tmp/tmptjRzW6/password.txt -n
Server-Cert cert-pki-ca
2020-06-20 15:09:48 pkispawn    : INFO     ....... importing permanent
SSL server cert into internal token: Server-Cert cert-pki-ca
2020-06-20 15:09:48 pki.nssdb   : DEBUG    Command: certutil -A -d
/var/lib/pki/pki-tomcat/alias -f /tmp/tmplJLOg8/internal_password.txt
-n Server-Cert cert-pki-ca -a -i /tmp/tmpeCzA_b/sslserver.crt -t ,,
2020-06-20 15:09:48 pkispawn    : INFO     ....... executing
'systemctl daemon-reload'
2020-06-20 15:09:48 pkispawn    : INFO     ....... executing
'systemctl start pki-tomcatd(a)pki-tomcat.service&#39;
2020-06-20 15:09:48 pkispawn    : INFO     ........... FIPS mode is
NOT enabled on this operating system.
2020-06-20 15:09:48 pkispawn    : DEBUG    ........... No connection -
server may still be down
2020-06-20 15:09:48 pkispawn    : DEBUG    ........... No connection -
exception thrown: ('Connection aborted.', error(111, 'Connection
refused'))
2020-06-20 15:09:49 pkispawn    : DEBUG    ........... No connection -
server may still be down
2020-06-20 15:09:49 pkispawn    : DEBUG    ........... No connection -
exception thrown: ('Connection aborted.', error(111, 'Connection
refused'))
2020-06-20 15:09:56 pkispawn    : DEBUG    ........... No connection -
server may still be down
2020-06-20 15:09:56 pkispawn    : DEBUG    ........... No connection -
exception thrown: 500 Server Error: Internal Server Error
2020-06-20 15:09:57 pkispawn    : DEBUG    ........... No connection -
server may still be down
2020-06-20 15:09:57 pkispawn    : DEBUG    ........... No connection -
exception thrown: 500 Server Error: Internal Server Error
2020-06-20 15:09:58 pkispawn    : DEBUG    ........... No connection -
server may still be down
... repeats every second
2020-06-20 15:10:47 pkispawn    : DEBUG    ........... No connection -
exception thrown: 500 Server Error: Internal Server Error
2020-06-20 15:10:48 pkispawn    : DEBUG    ........... No connection -
server may still be down
2020-06-20 15:10:48 pkispawn    : DEBUG    ........... No connection -
exception thrown: 500 Server Error: Internal Server Error
2020-06-20 15:10:49 pkispawn    : ERROR    ... server failed to restart
2020-06-20 15:10:49 pkispawn    : DEBUG    ....... Error Type: RuntimeError
2020-06-20 15:10:49 pkispawn    : DEBUG    ....... Error Message:
server failed to restart
2020-06-20 15:10:49 pkispawn    : DEBUG    .......   File
"/usr/sbin/pkispawn", line 534, in main
    scriptlet.spawn(deployer)
  File
"/usr/lib/python2.7/site-packages/pki/server/deployment/scriptlets/configuration.py",
line 1304, in spawn
    raise RuntimeError("server failed to restart")
######

And here is the failure in /var/log/ipareplica-ca-install.log:
######
...
---------------
Import complete
---------------
Imported certificates into /etc/pki/pki-tomcat/alias:

Certificate Nickname                                         Trust Attributes
                                                             SSL,S/MIME,JAR/XPI

Third-party RSA CA                                           C,,
caSigningCert cert-pki-ca                                    CTu,Cu,Cu
subsystemCert cert-pki-ca                                    u,u,u
auditSigningCert cert-pki-ca                                 u,u,Pu
Third-party Root CA                                          C,,
ocspSigningCert cert-pki-ca                                  u,u,u

Installation failed: server failed to restart

2020-06-20T15:10:50Z DEBUG stderr=pkispawn    : ERROR    ... server
failed to restart

2020-06-20T15:10:50Z CRITICAL Failed to configure CA instance: Command
'/usr/sbin/pkispawn -s CA -f /tmp/tmpcQ1jxM' returned non-zero exit
status 1
2020-06-20T15:10:50Z CRITICAL See the installation logs and the
following files/directories for more information:
2020-06-20T15:10:50Z CRITICAL   /var/log/pki/pki-tomcat
2020-06-20T15:10:50Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py",
line 567, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py",
line 557, in run_step
    method()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py",
line 675, in __spawn_instance
    pki_pin)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/dogtaginstance.py",
line 167, in spawn_instance
    self.handle_setup_error(e)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/dogtaginstance.py",
line 408, in handle_setup_error
    raise RuntimeError("%s configuration failed." % self.subsystem)
RuntimeError: CA configuration failed.

2020-06-20T15:10:50Z DEBUG   [error] RuntimeError: CA configuration failed.
...
######

Has anyone run into this?
Is this a known bug/issue?

Current environment of all replicas:
- CentOS 7.8
- FreeIPA 4.6.6

Any help/guidance on fixing this would be really appreciated.

Thanks so much,

Guillermo

2024

2023

2022

2021

2020

2019

2018

2017