Senior Systems Engineer
NCC Group
XYZ Building, 2 Hardman Boulevard, Spinningfields, Manchester, M3 3AQ
Telephone: +44 7703 501 120
Mobile: +44 7703 501 120
Website: www.nccgroup.trust
Twitter: @NCCGroupplc
Hi All,
I’m doing a basic CA installation of Dogtag 10.6 on RHEL 8 using an NCipher Connect HSM.
Installed Packages
Name : pki-ca
Version : 10.6.9
Release : 2.module+el8+2728+a4ad6bba
Arch : noarch
Size : 2.3 M
Source : pki-core-10.6.9-2.module+el8+2728+a4ad6bba.src.rpm
The installation runs through fine generating the private keys and public certs.
I’m using:
pkispawn -f ca.cfg -s CA -vv
But when it comes to near the end where it tries to fireup the final instance it fails.
From what I gather from the logs is that it’s having trouble understanding which private key is associated with the certificate.
I’ve had a look in the nssdb and I can see the public and private certs
[root@ ~]# certutil -L -d /var/lib/pki/pki-tomcat/alias -h accelerator -P accelerator
Certificate Nickname Trust Attributes
SSL,S/MIME,JAR/XPI
accelerator:ca_signing u,u,u
accelerator:ca_ocsp_signing u,u,u
accelerator:subsystem u,u,u
accelerator:ca_audit_signing u,u,u
accelerator:sslserver u,u,u
[root@ ~]# certutil -K -d /var/lib/pki/pki-tomcat/alias -h accelerator -P accelerator
certutil: Checking token "accelerator" in slot "XXXX-XXXX-XXXX Rt1"
< 0> rsa 53d1f55d8615a5bba2f65e24e506a51cc1830803 ca_signing
< 1> rsa 90d57df4f4fd65f3d54c6ee4461c141af59d9ead ca_ocsp_signing
< 2> rsa 3a9abb6b503489a6ebc4601bd4e3358626502325 accelerator:sslserver
< 3> rsa c707ad2ca6ab592c5f2658e92808a2d1952cd2eb subsystem
< 4> rsa 105f918fe93883fcba4a14319b8511b24bee9f7d ca_audit_signing
Debug console output from pkispawn:
configuration : INFO Removing temp SSL server cert from internal token: sslserver
pki.nssdb : DEBUG Command: certutil -F -d /var/lib/pki/pki-tomcat/alias -f /tmp/tmppzqg2r_k/password.txt -n sslserver
configuration : INFO Importing permanent SSL server cert into accelerator token: sslserver
pki.nssdb : DEBUG Command: certutil -A -d /var/lib/pki/pki-tomcat/alias -h accelerator -P accelerator -f /tmp/tmpbt1mgtq4/password.txt -n sslserver -a -i /tmp/tmp6nd6b9ne/sslserver.crt
-t
certutil: could not change trust on certificate: SEC_ERROR_TOKEN_NOT_LOGGED_IN: The operation failed because the PKCS#11 token is not logged in.
pki.nssdb : WARNING certutil returned non-zero exit code (bug #1393668)
pkihelper : INFO Starting pki-tomcat instance
pkihelper : DEBUG Command: systemctl daemon-reload
pkihelper : DEBUG Command: systemctl start
pki-tomcatd@pki-tomcat.service
pkihelper : INFO FIPS mode is enabled on this operating system.
pkispawn : INFO Checking server at
http://sc.test.com:8080/ca
pkispawn : INFO Waiting for server to start (1s)
pkispawn : INFO Waiting for server to start (2s)
pkispawn : INFO Waiting for server to start (3s)
pkispawn : INFO Waiting for server to start (4s)
Installation failed:
<!doctype html><html lang="en"><head><title>HTTP Status 500 – Internal Server Error</title><style type="text/css">h1 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:22px;}
h2 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:16px;} h3 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:14px;} body {font-family:Tahoma,Arial,sans-serif;color:black;background-color:white;}
b {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;} p {font-family:Tahoma,Arial,sans-serif;background:white;color:black;font-size:12px;} a {color:black;} a.name {color:black;} .line {height:1px;background-color:#525D76;border:none;}</style></head><body><h1>HTTP
Status 500 – Internal Server Error</h1><hr class="line" /><p><b>Type</b> Exception Report</p><p><b>Message</b> Subsystem unavailable</p><p><b>Description</b> The server encountered an unexpected condition that prevented it from fulfilling the request.</p><p><b>Exception</b></p><pre>javax.ws.rs.ServiceUnavailableException:
Subsystem unavailable
com.netscape.cms.tomcat.ProxyRealm.findSecurityConstraints(ProxyRealm.java:150)
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:483)
com.netscape.cms.tomcat.ExternalAuthenticationValve.invoke(ExternalAuthenticationValve.java:82)
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:651)
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:414)
org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:754)
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1376)
org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
java.lang.Thread.run(Thread.java:748)
</pre><p><b>Note</b> The full stack trace of the root cause is available in the server logs.</p><hr class="line" /><h3>Apache Tomcat/9.0.7.redhat-10</h3></body></html>
Debug output from /var/log/pki/pki-tomcat/ca/debug.log
2019-07-01 14:00:57 [main] FINE: CertificateAuthority: size: 977 bytes
2019-07-01 14:00:57 [main] FINE: CertificateAuthority: subject DN: CN=CA Signing Certificate,OU=pki-tomcat,O=sc.test.com
2019-07-01 14:00:57 [main] FINE: CertificateAuthority: issuer DN: CN=CA Signing Certificate,OU=pki-tomcat,O=sc.test.com
2019-07-01 14:00:57 [main] FINE: CA SigningUnit.init(ca, ca.signing, null)
2019-07-01 14:00:57 [main] FINE: Setting ca.signing.newNickname=accelerator:ca_signing
2019-07-01 14:00:57 [main] FINE: SigningUnit: Loading certificate accelerator:ca_signing
2019-07-01 14:00:57 [main] FINE: SigningUnit: certificate serial number: 1
2019-07-01 14:00:57 [main] FINE: SigningUnit: Loading private key
2019-07-01 14:00:57 [main] FINE: SigningUnit: private key ID: 53d1f55d8615a5bba2f65e24e506a51cc1830803
2019-07-01 14:00:57 [main] SEVERE: Exception: Algorithm SHA256withRSA is not supported for the signing token and key
Algorithm SHA256withRSA is not supported for the signing token and key
at com.netscape.ca.SigningUnit.checkSigningAlgorithmFromName(SigningUnit.java:249)
at com.netscape.ca.SigningUnit.init(SigningUnit.java:186)
at com.netscape.ca.CertificateAuthority.initSigUnit(CertificateAuthority.java:1722)
at com.netscape.ca.CertificateAuthority.init(CertificateAuthority.java:547)
at com.netscape.cmscore.apps.CMSEngine.initSubsystem(CMSEngine.java:975)
at com.netscape.cmscore.apps.CMSEngine.initSubsystems(CMSEngine.java:833)
at com.netscape.cmscore.apps.CMSEngine.initSubsystems(CMSEngine.java:826)
at com.netscape.cmscore.apps.CMSEngine.init(CMSEngine.java:491)
at com.netscape.cms.servlet.base.CMSStartServlet.init(CMSStartServlet.java:149)
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:282)
at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:279)
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:314)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:170)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:123)
at org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1112)
at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1079)
at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:971)
at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4788)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5100)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:742)
at org.apache.catalina.core.ContainerBase.access$000(ContainerBase.java:130)
at org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:151)
at org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:141)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:716)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:703)
at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:630)
at org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1839)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:112)
at org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java:525)
at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:424)
at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1585)
at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:308)
at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
at org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:424)
at org.apache.catalina.util.LifecycleBase.setState(LifecycleBase.java:367)
at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:966)
at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:839)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1427)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1417)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:134)
at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:943)
at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:258)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
at org.apache.catalina.core.StandardService.startInternal(StandardService.java:422)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:770)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
at org.apache.catalina.startup.Catalina.start(Catalina.java:682)
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.startup.Bootstrap.start(Bootstrap.java:350)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:492)
Caused by: java.security.InvalidKeyException: org.mozilla.jss.crypto.NoSuchItemOnTokenException: Key is not present on this token
at org.mozilla.jss.pkcs11.PK11Signature.engineInitSign(PK11Signature.java:78)
at org.mozilla.jss.crypto.Signature.initSign(Signature.java:55)
at com.netscape.ca.SigningUnit.checkSigningAlgorithmFromName(SigningUnit.java:235)
... 68 more
I noticed the entry
pki.nssdb : DEBUG Command: certutil -A -d /var/lib/pki/pki-tomcat/alias -h accelerator -P accelerator -f /tmp/tmpbt1mgtq4/password.txt -n sslserver -a -i /tmp/tmp6nd6b9ne/sslserver.crt
-t
certutil: could not change trust on certificate: SEC_ERROR_TOKEN_NOT_LOGGED_IN: The operation failed because the PKCS#11 token is not logged in.
pki.nssdb : WARNING certutil returned non-zero exit code (bug #1393668)
However I believe this relates to an old bug as it indicates using nss with pkcs11 interfaces will fail but when I look in the nssdb the cert is present.
The issue I think is around the system getting access to the private key for the ca_signing cert
Caused by: java.security.InvalidKeyException: org.mozilla.jss.crypto.NoSuchItemOnTokenException: Key is not present on this token
Could it be as simple as it’s looking in the local store instead of the HSM backed location as this does have certificates present for some reason.
[root@ ~]# certutil -L -d /var/lib/pki/pki-tomcat/alias
Certificate Nickname Trust Attributes
SSL,S/MIME,JAR/XPI
ca_signing CT,C,C
ca_audit_signing ,,P
[root@ ~]# certutil -K -d /var/lib/pki/pki-tomcat/alias
certutil: Checking token "NSS Certificate DB" in slot "NSS User Private Key and Certificate Services"
Enter Password or Pin for "NSS Certificate DB":
certutil: no keys found
As expected the local nssdb does not have the keys present.
Any ideas or pointers would be greatly appreciated.
Oh just to add this works on RHEL 7.6 with dogtag 10.5.9
Also not sure why it thinks I’m running in FIPS mode. When I check it seems to suggest not.
[root@ ~]# sysctl crypto.fips_enabled
crypto.fips_enabled = 0
Thanks
Dave Etchen
| David Etchen Senior Systems Engineer NCC Group XYZ Building, 2 Hardman Boulevard, Spinningfields, Manchester, M3 3AQ Telephone: +44 7703 501 120 Mobile: +44 7703 501 120 Website: www.nccgroup.trust Twitter: @NCCGroupplc |
|
This email is sent for and on behalf of NCC Group. NCC Group is the trading name of NCC Services Limited (Registered in England CRN: 2802141). The ultimate holding company is NCC Group plc (Registered in England CRN: 4627044). This email may be confidential and/or legally privileged.