Note: This bug is displayed in read-only format because
the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Description of problem:
There are couple of places which needs logging improvement.Because logs might mislead and are not user friendly.
Scenario 1 :
-----------
ExternalCA installation debug logs throws below mentioned exception.When we check nssdb all certs exist but still it shows issues.
<debug logs snip>
SigningUnit: Certificate object not found
Certificate object not found
</debug logs snip>
nssdb:
certutil -L -d /root/testLuna -h lunasaQE | grep Test_ExternalCA3
Enter Password or Pin for "lunasaQE":
lunasaQE:gkapoor/Test_ExternalCA3/subsystem u,u,u
lunasaQE:gkapoor/Test_ExternalCA3/sslserver/nocp30.idm.lab.eng.rdu2.redhat.com u,u,u
lunasaQE:gkapoor/Test_ExternalCA3/ca_ocsp_signing u,u,u
lunasaQE:gkapoor/Test_ExternalCA3/ca_audit_signing u,u,u
lunasaQE:gkapoor/Test_ExternalCA3/ca_signing u,u,u
lunasaQE:gkapoor/Test_ExternalCA3/External CA1 ,,
Scenario 2:
-----------
Whenever CA failed to restart maybe ports/address in use or because of any other exception we always see a NPE .Can we have better logging for this.
Installation logs:
==================
pkispawn : DEBUG ........... No connection - server may still be down
pkispawn : DEBUG ........... No connection - exception thrown: ('Connection aborted.', error(111, 'Connection refused'))
pkispawn : ERROR ....... server failed to restart
pkispawn : DEBUG ....... Error Type: Exception
pkispawn : DEBUG ....... Error Message: server failed to restart
pkispawn : DEBUG ....... File "/usr/sbin/pkispawn", line 528, in main
scriptlet.spawn(deployer)
File "/usr/lib/python2.7/site-packages/pki/server/deployment/scriptlets/configuration.py", line 375, in spawn
raise Exception("server failed to restart")
Installation failed: server failed to restart
localhost/catlina logs:
========================
Nov 07, 2016 6:20:49 AM org.apache.catalina.core.ApplicationContext log
SEVERE: Servlet castart threw unload() exception
javax.servlet.ServletException: Servlet.destroy() for servlet castart threw exception
at org.apache.catalina.core.StandardWrapper.unload(StandardWrapper.java:1505)
at org.apache.catalina.core.StandardWrapper.stopInternal(StandardWrapper.java:1846)
at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:224)
at org.apache.catalina.core.StandardContext.stopInternal(StandardContext.java:5767)
at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:224)
at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1588)
at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1577)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException
at com.netscape.cmscore.profile.ProfileSubsystem.shutdown(ProfileSubsystem.java:225)
at com.netscape.cmscore.apps.CMSEngine.shutdownSubsystems(CMSEngine.java:2115)
at com.netscape.cmscore.apps.CMSEngine.shutdown(CMSEngine.java:2010)
at com.netscape.certsrv.apps.CMS.shutdown(CMS.java:233)
at com.netscape.cms.servlet.base.CMSStartServlet.destroy(CMSStartServlet.java:144)
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)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:175)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:102)
at org.apache.catalina.core.StandardWrapper.unload(StandardWrapper.java:1478)
... 10 more
10.3.3.13
How reproducible:
always
Steps to Reproduce:
1. Scenario 1 can be seen in externalCA with hsm
2. Scenario 2 can be recreated when CA installation failed during CA server restart.
3.
Actual results:
Expected results:
Additional info:
additional logs for scenario 1:
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Established LDAP connection using basic authentication to host nocp30.idm.lab.eng.rdu2.redhat.com port 3389 as cn=Directory Manager
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: initializing with mininum 3 and maximum 15 connections to host nocp30.idm.lab.eng.rdu2.redhat.com port 3389, secure connection, false, authentication type 1
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: increasing minimum connections by 3
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: new total available connections 3
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: new number of connections 3
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Cert Repot inited
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: CRL Repot inited
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Replica Repot inited
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: CertificateAuthority:initSigUnit: ca cert found
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: CertificateAuthority: initSigUnit 1- setting mIssuerObj and mSubjectObj
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: ca.signing Signing Unit nickname lunasaQE:gkapoor/Test_ExternalCA3/ca_signing
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Got token lunasaQE by name
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Found cert by nickname: 'lunasaQE:gkapoor/Test_ExternalCA3/ca_signing' with serial number: 15938
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: converted to x509CertImpl
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Got private key from cert
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Got public key from cert
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: got signing algorithm RSASignatureWithSHA512Digest
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: CA signing unit inited
[15/Nov/2016:01:49:25][http-bio-31142-exec-3]: cachainNum= 0
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: in init - got CA chain from JSS.
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: ca.ocsp_signing Signing Unit nickname ocspSigningCert cert-Test_ExternalCA3
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: Got token internal by name
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: SigningUnit: Certificate object not found
Certificate object not found
at com.netscape.ca.SigningUnit.init(SigningUnit.java:174)
at com.netscape.ca.SigningUnit.init(SigningUnit.java:131)
at com.netscape.ca.CertificateAuthority.initSigUnit(CertificateAuthority.java:1667)
at com.netscape.ca.CertificateAuthority.init(CertificateAuthority.java:525)
at com.netscape.cmscore.apps.CMSEngine.reinit(CMSEngine.java:1344)
at com.netscape.certsrv.apps.CMS.reinit(CMS.java:191)
at com.netscape.cms.servlet.csadmin.ConfigurationUtils.reInitSubsystem(ConfigurationUtils.java:2300)
at org.dogtagpki.server.rest.SystemConfigService.configure(SystemConfigService.java:181)
at org.dogtagpki.server.rest.SystemConfigService.configure(SystemConfigService.java:121)
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.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:137)
at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:280)
at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:234)
at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:221)
at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:356)
at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:179)
at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:220)
at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(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(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)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:175)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:297)
at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:55)
at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:191)
at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:187)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.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(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)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:260)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237)
at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:55)
at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:191)
at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:187)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:186)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.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(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:436)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1078)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.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(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.mozilla.jss.crypto.ObjectNotFoundException
at org.mozilla.jss.CryptoManager.findCertByNicknameNative(Native Method)
at org.mozilla.jss.CryptoManager.findCertByNickname(CryptoManager.java:1235)
at com.netscape.ca.SigningUnit.init(SigningUnit.java:171)
... 70 more
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CertificateAuthority.init(): Swallow exception in pre-op mode
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CertificateAuthority init: initRequestQueue
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: selected policy processor = classic
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: GenericPolicyProcessor::init begins
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: GenericPolicyProcessor::init Certificate Policy Framework (deprecated) is DISABLED
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CA policy inited
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CA service inited
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CA notifier inited
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CA pending notifier inited
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: RequestRepository: constructor2.
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CertificateAuthority.init(): Abort in pre-op mode
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: Creating LdapAnonConnFactory(PasswdUserDBAuthentication)
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: increasing minimum number of connections by 3
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: new total number of connections 3
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: new total available connections 3
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: AuthSubsystem: initializing authentication manager AgentCertAuth
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: AuthSubsystem: initializing authentication manager SSLclientCertAuth
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: AuthSubsystem: initializing authentication manager TokenAuth
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: AuthSubsystem: initializing authentication manager flatFileAuth
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: FlatFileAuth: Splitting String: UID on commas
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: FlatFileAuth: countTokens:1
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: FlatFileAuth: token 0 = UID
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: FlatFileAuth: Splitting String: PWD on commas
[15/Nov/2016:01:49:26][http-bio-31142-exec-3]: FlatFileAuth: countTokens:1
Description of problem: There are couple of places which needs logging improvement.Because logs might mislead and are not user friendly. Scenario 1 : ----------- ExternalCA installation debug logs throws below mentioned exception.When we check nssdb all certs exist but still it shows issues. <debug logs snip> SigningUnit: Certificate object not found Certificate object not found </debug logs snip> nssdb: certutil -L -d /root/testLuna -h lunasaQE | grep Test_ExternalCA3 Enter Password or Pin for "lunasaQE": lunasaQE:gkapoor/Test_ExternalCA3/subsystem u,u,u lunasaQE:gkapoor/Test_ExternalCA3/sslserver/nocp30.idm.lab.eng.rdu2.redhat.com u,u,u lunasaQE:gkapoor/Test_ExternalCA3/ca_ocsp_signing u,u,u lunasaQE:gkapoor/Test_ExternalCA3/ca_audit_signing u,u,u lunasaQE:gkapoor/Test_ExternalCA3/ca_signing u,u,u lunasaQE:gkapoor/Test_ExternalCA3/External CA1 ,, Scenario 2: ----------- Whenever CA failed to restart maybe ports/address in use or because of any other exception we always see a NPE .Can we have better logging for this. Installation logs: ================== pkispawn : DEBUG ........... No connection - server may still be down pkispawn : DEBUG ........... No connection - exception thrown: ('Connection aborted.', error(111, 'Connection refused')) pkispawn : ERROR ....... server failed to restart pkispawn : DEBUG ....... Error Type: Exception pkispawn : DEBUG ....... Error Message: server failed to restart pkispawn : DEBUG ....... File "/usr/sbin/pkispawn", line 528, in main scriptlet.spawn(deployer) File "/usr/lib/python2.7/site-packages/pki/server/deployment/scriptlets/configuration.py", line 375, in spawn raise Exception("server failed to restart") Installation failed: server failed to restart localhost/catlina logs: ======================== Nov 07, 2016 6:20:49 AM org.apache.catalina.core.ApplicationContext log SEVERE: Servlet castart threw unload() exception javax.servlet.ServletException: Servlet.destroy() for servlet castart threw exception at org.apache.catalina.core.StandardWrapper.unload(StandardWrapper.java:1505) at org.apache.catalina.core.StandardWrapper.stopInternal(StandardWrapper.java:1846) at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:224) at org.apache.catalina.core.StandardContext.stopInternal(StandardContext.java:5767) at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:224) at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1588) at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1577) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: java.lang.NullPointerException at com.netscape.cmscore.profile.ProfileSubsystem.shutdown(ProfileSubsystem.java:225) at com.netscape.cmscore.apps.CMSEngine.shutdownSubsystems(CMSEngine.java:2115) at com.netscape.cmscore.apps.CMSEngine.shutdown(CMSEngine.java:2010) at com.netscape.certsrv.apps.CMS.shutdown(CMS.java:233) at com.netscape.cms.servlet.base.CMSStartServlet.destroy(CMSStartServlet.java:144) 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) at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:175) at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:102) at org.apache.catalina.core.StandardWrapper.unload(StandardWrapper.java:1478) ... 10 more 10.3.3.13 How reproducible: always Steps to Reproduce: 1. Scenario 1 can be seen in externalCA with hsm 2. Scenario 2 can be recreated when CA installation failed during CA server restart. 3. Actual results: Expected results: Additional info: additional logs for scenario 1: [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Established LDAP connection using basic authentication to host nocp30.idm.lab.eng.rdu2.redhat.com port 3389 as cn=Directory Manager [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: initializing with mininum 3 and maximum 15 connections to host nocp30.idm.lab.eng.rdu2.redhat.com port 3389, secure connection, false, authentication type 1 [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: increasing minimum connections by 3 [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: new total available connections 3 [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: new number of connections 3 [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Cert Repot inited [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: CRL Repot inited [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Replica Repot inited [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: CertificateAuthority:initSigUnit: ca cert found [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: CertificateAuthority: initSigUnit 1- setting mIssuerObj and mSubjectObj [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: ca.signing Signing Unit nickname lunasaQE:gkapoor/Test_ExternalCA3/ca_signing [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Got token lunasaQE by name [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Found cert by nickname: 'lunasaQE:gkapoor/Test_ExternalCA3/ca_signing' with serial number: 15938 [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: converted to x509CertImpl [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Got private key from cert [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: Got public key from cert [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: got signing algorithm RSASignatureWithSHA512Digest [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: CA signing unit inited [15/Nov/2016:01:49:25][http-bio-31142-exec-3]: cachainNum= 0 [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: in init - got CA chain from JSS. [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: ca.ocsp_signing Signing Unit nickname ocspSigningCert cert-Test_ExternalCA3 [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: Got token internal by name [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: SigningUnit: Certificate object not found Certificate object not found at com.netscape.ca.SigningUnit.init(SigningUnit.java:174) at com.netscape.ca.SigningUnit.init(SigningUnit.java:131) at com.netscape.ca.CertificateAuthority.initSigUnit(CertificateAuthority.java:1667) at com.netscape.ca.CertificateAuthority.init(CertificateAuthority.java:525) at com.netscape.cmscore.apps.CMSEngine.reinit(CMSEngine.java:1344) at com.netscape.certsrv.apps.CMS.reinit(CMS.java:191) at com.netscape.cms.servlet.csadmin.ConfigurationUtils.reInitSubsystem(ConfigurationUtils.java:2300) at org.dogtagpki.server.rest.SystemConfigService.configure(SystemConfigService.java:181) at org.dogtagpki.server.rest.SystemConfigService.configure(SystemConfigService.java:121) 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.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:137) at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:280) at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:234) at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:221) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:356) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:179) at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:220) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(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(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) at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:175) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:297) at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:55) at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:191) at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:187) at java.security.AccessController.doPrivileged(Native Method) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.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(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) at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:260) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237) at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:55) at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:191) at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:187) at java.security.AccessController.doPrivileged(Native Method) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:186) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.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(StandardEngineValve.java:116) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:436) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1078) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.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(TaskThread.java:61) at java.lang.Thread.run(Thread.java:745) Caused by: org.mozilla.jss.crypto.ObjectNotFoundException at org.mozilla.jss.CryptoManager.findCertByNicknameNative(Native Method) at org.mozilla.jss.CryptoManager.findCertByNickname(CryptoManager.java:1235) at com.netscape.ca.SigningUnit.init(SigningUnit.java:171) ... 70 more [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CertificateAuthority.init(): Swallow exception in pre-op mode [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CertificateAuthority init: initRequestQueue [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: selected policy processor = classic [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: GenericPolicyProcessor::init begins [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: GenericPolicyProcessor::init Certificate Policy Framework (deprecated) is DISABLED [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CA policy inited [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CA service inited [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CA notifier inited [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CA pending notifier inited [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: RequestRepository: constructor2. [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: CertificateAuthority.init(): Abort in pre-op mode [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: Creating LdapAnonConnFactory(PasswdUserDBAuthentication) [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: increasing minimum number of connections by 3 [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: new total number of connections 3 [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: new total available connections 3 [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: AuthSubsystem: initializing authentication manager AgentCertAuth [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: AuthSubsystem: initializing authentication manager SSLclientCertAuth [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: AuthSubsystem: initializing authentication manager TokenAuth [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: AuthSubsystem: initializing authentication manager flatFileAuth [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: FlatFileAuth: Splitting String: UID on commas [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: FlatFileAuth: countTokens:1 [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: FlatFileAuth: token 0 = UID [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: FlatFileAuth: Splitting String: PWD on commas [15/Nov/2016:01:49:26][http-bio-31142-exec-3]: FlatFileAuth: countTokens:1