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'
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'
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