While performing External CA testing with HSM( lunasa) observed that :
1. During installation pkispawn will import the CA signing cert with the specified nickname into the NSS database. Then pkispawn will import all certs in the cert chain with different nicknames. The problem is, if the supplied PKCS #7 file contains the new CA signing cert, the cert will be imported again. When a cert is imported twice, with internal token the first nickname will be retained. However, apparently with Luna SA the second nickname will overwrite the first one, so the CA signing cert will have a wrong nickname in Luna SA, causing the above exception. 2. I tried two test :: 1. Signing dogtag CA with openssl . 2. Signing dogtag CA using nssdb . Below mentioned behavior is common in both installation test (openssl/nssdb). 1. Installation went through fine but logs shows below log stack.Below is the pastebin link. http://pastebin.test.redhat.com/413035 ** Unable to read key retriever class 2. I tried few negative test cases like I am seeing "NPE" if the certificate is old cert. 3. If External CA certs already exist is the Lunasa HSM box we see below exceptions. http://pastebin.test.redhat.com/412603 1 is positive test case. 2,3 are negative test cases but its difficult to identify what went wrong here.
How reproducible:
This can be seen with ExternalCA with Lunasa.
Steps to Reproduce:
External CA needs to be configured here
Additional info:Logs::
http://pastebin.test.redhat.com/413035 [19/Sep/2016:02:46:49][KeyRetrieverRunner-5bdfcd18-d4a3-47be-a99f-cd0891859713] : Unable to read key retriever class from CS.cfg: Property features.authority.keyRetrieverClass missing value [19/Sep/2016:02:46:49][KeyRetrieverRunner-5bdfcd18-d4a3-47be-a99f-cd0891859713] : Retrying in 15 seconds [19/Sep/2016:02:47:04][KeyRetrieverRunner-5bdfcd18-d4a3-47be-a99f-cd0891859713] : Unable to read key retriever class from CS.cfg: Property features.authority.keyRetrieverClass missing value [19/Sep/2016:02:47:04][KeyRetrieverRunner-5bdfcd18-d4a3-47be-a99f-cd0891859713] : Retrying in 22 seconds [19/Sep/2016:02:47:27][KeyRetrieverRunner-5bdfcd18-d4a3-47be-a99f-cd0891859713] : Unable to read key retriever class from CS.cfg: Property features.authority.keyRetrieverClass missing value [19/Sep/2016:02:47:27][KeyRetrieverRunner-5bdfcd18-d4a3-47be-a99f-cd0891859713] : Retrying in 33 seconds [19/Sep/2016:02:48:00][KeyRetrieverRunner-5bdfcd18-d4a3-47be-a99f-cd0891859713] : Unable to read key retriever class from CS.cfg: Property features.authority.keyRetrieverClass missing value [19/Sep/2016:02:48:00][KeyRetrieverRunner-5bdfcd18-d4a3-47be-a99f-cd0891859713] : Retrying in 50 seconds [19/Sep/2016:02:48:51][KeyRetrieverRunner-5bdfcd18-d4a3-47be-a99f-cd0891859713] : Unable to read key retriever class from CS.cfg: Property features.authority.keyRetrieverClass missing value [19/Sep/2016:02:48:51][KeyRetrieverRunner-5bdfcd18-d4a3-47be-a99f-cd0891859713] : Retrying in 75 seconds [19/Sep/2016:02:50:07][KeyRetrieverRunner-5bdfcd18-d4a3-47be-a99f-cd0891859713] : Unable to read key retriever class from CS.cfg: Property features.authority.keyRetrieverClass missing value [19/Sep/2016:02:50:07][KeyRetrieverRunner-5bdfcd18-d4a3-47be-a99f-cd0891859713] : Retrying in 113 second 2. http://pastebin.test.redhat.com/412603 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: In DBVirtualList filter attrs startFrom sortKey pageSize filter: (requeststate=*) attrs: null pageSize -5 startFrom 0810000000 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: returnConn: mNumConns now 3 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: DBVirtualList: searching for entry 0810000000 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: DBVirtualList.getEntries() [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: DBVirtualList: entries: 0 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: DBVirtualList: top: 0 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: DBVirtualList: size: 0 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: RequestQueue: getLastRequestId: size 0 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: RequestQueue: getSizeBeforeJumpTo: 0 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: RequestQueue: getLastRequestId: request list is empty. [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: CertificateRepository:getLastCertRecordSerialNo: returning 1 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: Repository: mLastSerialNo: 1 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: Repository: checkRange mLastSerialNo=2 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: Repository: getNextSerialNumber: returning retSerial 2 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: certUtil: newRequest called [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: certUtil: calling setRequestStatus [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: CertUtil profile name= caOCSPCert.profile [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: CertInfoProfile: Populating certificate with com.netscape.cms.profile.def.ValidityDefault [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: ValidityDefault: start time: 0 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: ValidityDefault: not before: Fri Sep 16 03:05:30 EDT 2016 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: ValidityDefault: range: 720 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: ValidityDefault: range unit: day [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: ValidityDefault: not after: Thu Sep 06 03:05:30 EDT 2018 [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: ValidityDefault: populate: adjustValidity is true [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: CertInfoProfile: Unable to populate certificate: Unable to get ca certificate: Unable to initialize, java.io.IOException: extra DER value data (constructor) [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: Unable to create local certificate: Unable to get ca certificate: Unable to initialize, java.io.IOException: extra DER value data (constructor) [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: configCert() exception caught:java.io.IOException: Unable to create local certificate: Unable to get ca certificate: Unable to initialize, java.io.IOException: extra DER value data (constructor) java.io.IOException: Unable to create local certificate: Unable to get ca certificate: Unable to initialize, java.io.IOException: extra DER value data (constructor) at com.netscape.cms.servlet.csadmin.CertUtil.createLocalCert(CertUtil.java:602) at com.netscape.cms.servlet.csadmin.CertUtil.createLocalCert(CertUtil.java:417) at com.netscape.cms.servlet.csadmin.ConfigurationUtils.configCert(Confi gurationUtils.java:2727) at org.dogtagpki.server.rest.SystemConfigService.processCert(SystemConf igService.java:490) at org.dogtagpki.server.rest.SystemConfigService.processCerts(SystemCon figService.java:387) at org.dogtagpki.server.rest.SystemConfigService.configure(SystemConfig Service.java:187) at org.dogtagpki.server.rest.SystemConfigService.configure(SystemConfig Service.java:121) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcce ssorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:137) at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(Resourc eMethodInvoker.java:280) at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodI nvoker.java:234) at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodI nvoker.java:221) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDisp atcher.java:356) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDisp atcher.java:179) at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher .service(ServletContainerDispatcher.java:220) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.serv ice(HttpServletDispatcher.java:56) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.serv ice(HttpServletDispatcher.java:51) at javax.servlet.http.HttpServlet.service(HttpServlet.java:731) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcce ssorImpl.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) at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:175) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(App licationFilterChain.java:297) at org.apache.catalina.core.ApplicationFilterChain.access$000(Applicati onFilterChain.java:55) at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFil terChain.java:191) at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFil terChain.java:187) at java.security.AccessController.doPrivileged(Native Method) at org.apache.catalina.core.ApplicationFilterChain.doFilter(Application FilterChain.java:186) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcce ssorImpl.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) at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:260) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(App licationFilterChain.java:237) at org.apache.catalina.core.ApplicationFilterChain.access$000(Applicati onFilterChain.java:55) at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFil terChain.java:191) at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFil terChain.java:187) at java.security.AccessController.doPrivileged(Native Method) at org.apache.catalina.core.ApplicationFilterChain.doFilter(Application FilterChain.java:186) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapper Valve.java:220) at org.apache.catalina.core.StandardContextValve.invoke(StandardContext Valve.java:122) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(Authentic atorBase.java:505) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineVa lve.java:116) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:436) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHtt p11Processor.java:1078) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process (AbstractProtocol.java:625) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoi nt.java:316) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskT hread.java:61) at java.lang.Thread.run(Thread.java:745) Caused by: Unable to get ca certificate: Unable to initialize, java.io.IOException: extra DER value data (constructor) at com.netscape.cms.profile.def.ValidityDefault.populate(ValidityDefault.java:323) at com.netscape.certsrv.profile.CertInfoProfile.populate(CertInfoProfile.java:100) at com.netscape.cms.servlet.csadmin.CertUtil.createLocalCert(CertUtil.java:546) ... 68 more Caused by: Unable to initialize, java.io.IOException: extra DER value data (constructor) at com.netscape.ca.CertificateAuthority.getCACert(CertificateAuthority.java:1494) at com.netscape.cms.profile.def.ValidityDefault.populate(ValidityDefault.java:315) ... 70 more Caused by: java.security.cert.CertificateException: Unable to initialize, java.io.IOException: extra DER value data (constructor) at netscape.security.x509.X509CertImpl.<init>(X509CertImpl.java:186) at netscape.security.x509.X509CertImpl.<init>(X509CertImpl.java:160) at com.netscape.ca.CertificateAuthority.getCACert(CertificateAuthority.java:1486) ... 71 more [16/Sep/2016:03:05:30][http-bio-30142-exec-3]: Error in setting certificate names and key sizes: java.io.IOException: Unable to create local certificate: Unable to get ca certificate: Unable to initialize, java.io.IOException: extra DER value data (constructor)
Metadata Update from @gkapoor: - Issue set to the milestone: UNTRIAGED
Metadata Update from @mharmsen: - Custom field feature adjusted to '' - Custom field proposedmilestone adjusted to '' - Custom field proposedpriority adjusted to '' - Custom field reviewer adjusted to '' - Custom field version adjusted to '' - Issue close_status updated to: None - Issue priority set to: 2 (was: 3) - Issue set to the milestone: 10.4 (was: UNTRIAGED)
Per PKI Bug Council of 04/05/2017: 10.5
Metadata Update from @mharmsen: - Issue set to the milestone: 10.5 (was: 10.4)
Metadata Update from @mharmsen: - Issue priority set to: major (was: critical)
[20171025] - Offline Triage ==> 10.6
Metadata Update from @mharmsen: - Issue set to the milestone: 10.6 (was: 10.5)
Per 10.5.x/10.6 Triage: 10.5
cfu: I think it should be fixed at the earliest convenience when migration is expected
Metadata Update from @mharmsen: - Issue priority set to: critical (was: major) - Issue set to the milestone: 10.5 (was: 10.6)
Metadata Update from @mharmsen: - Issue assigned to edewata
Metadata Update from @mharmsen: - Custom field rhbz adjusted to https://bugzilla.redhat.com/show_bug.cgi?id=1378539, https://bugzilla.redhat.com/show_bug.cgi?id=1424712 (was: https://bugzilla.redhat.com/show_bug.cgi?id=1378539)
Metadata Update from @mharmsen: - Assignee reset
See additional comments and stacktraces in corresponding bz: https://bugzilla.redhat.com/show_bug.cgi?id=1378539
Dogtag PKI is moving from Pagure issues to GitHub issues. This means that existing or new issues will be reported and tracked through Dogtag PKI's GitHub Issue tracker.
This issue has been cloned to GitHub and is available here: https://github.com/dogtagpki/pki/issues/2600
If you want to receive further updates on the issue, please navigate to the GitHub issue and click on Subscribe button.
Subscribe
Thank you for understanding, and we apologize for any inconvenience.
Metadata Update from @dmoluguw: - Issue close_status updated to: migrated - Issue status updated to: Closed (was: Open)