#2480 Failure point while doing ExternalCA with HSM
Closed: migrated by dmoluguw. Opened by gkapoor.

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:
- Issue set to the milestone: 10.6 (was: 10.5)

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.

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)

Metadata