search

pki-bot / pki-issues-final

0 stars 0 forks source link

Failure point while doing ExternalCA with HSM #2029

Open pki-bot opened 4 years ago

pki-bot commented 4 years ago

This issue was migrated from Pagure Issue #2480. Originally filed by gkapoor (@geetikakay) on 2016-09-27 00:01:34:

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)
pki-bot commented 4 years ago

Comment from gkapoor (@geetikakay) at 2017-02-27 14:01:21

Metadata Update from @geetikakay:

pki-bot commented 4 years ago

Comment from mharmsen (@mharmsen) at 2017-03-03 21:01:27

Metadata Update from @mharmsen:

pki-bot commented 4 years ago

Comment from mharmsen (@mharmsen) at 2017-04-06 17:21:06

Per PKI Bug Council of 04/05/2017: 10.5

pki-bot commented 4 years ago

Comment from mharmsen (@mharmsen) at 2017-04-06 17:21:08

Metadata Update from @mharmsen:

pki-bot commented 4 years ago

Comment from mharmsen (@mharmsen) at 2017-09-01 11:38:20

Metadata Update from @mharmsen:

pki-bot commented 4 years ago

Comment from mharmsen (@mharmsen) at 2017-10-25 17:41:05

[20171025] - Offline Triage ==> 10.6

pki-bot commented 4 years ago

Comment from mharmsen (@mharmsen) at 2017-10-25 17:41:08

Metadata Update from @mharmsen:

pki-bot commented 4 years ago

Comment from mharmsen (@mharmsen) at 2018-04-26 21:34:48

Per 10.5.x/10.6 Triage: 10.5

cfu: I think it should be fixed at the earliest convenience when migration is expected

pki-bot commented 4 years ago

Comment from mharmsen (@mharmsen) at 2018-04-26 21:34:49

Metadata Update from @mharmsen:

pki-bot commented 4 years ago

Comment from mharmsen (@mharmsen) at 2018-05-04 19:38:02

Metadata Update from @mharmsen:

pki-bot commented 4 years ago

Comment from mharmsen (@mharmsen) at 2018-09-21 20:21:44

Metadata Update from @mharmsen:

pki-bot commented 4 years ago

Comment from mharmsen (@mharmsen) at 2018-09-26 20:18:53

Metadata Update from @mharmsen:

pki-bot commented 4 years ago

Comment from mharmsen (@mharmsen) at 2018-10-23 20:07:07

Metadata Update from @mharmsen:

pki-bot commented 4 years ago

Comment from cipherboy (@cipherboy) at 2020-03-15 12:37:45

See additional comments and stacktraces in corresponding bz: https://bugzilla.redhat.com/show_bug.cgi?id=1378539