Hi Guys,
I have a 2 host basic IPA setup both IPA servers are running dns & ca.
I'm running on Centos 7.6 using freeipa version 4.6.4 & dogtag version 10.5.9
I've made a subCA called vpnca and a certificate policy and all this is working
fine with the exception of OCSP on the 2nd IPA box.
The original master works fine and issues OCSP responses for certifcates issued
by the vpnca (subCA) however the replica IPA box fails to respond.
I've had a look through the logs and found in the
/var/log/pki/pki-tomcat/ca/debug log an error on the 2nd box when doing an OCSP
request against it for a certificate issued by the subCA.
I should note here that OCSP requests for certificates issued by the main IPA
CA work fine it's only for ones issued by the subCA on the replica that seem to
be broken.
I have also spotted the 2nd IPA server complaining that is can't get
caSigningCert
[04/Sep/2019:13:24:01][KeyRetrieverRunner-dd4ea812-c044-41c0-93bf-ec376c732c93]:
Running ExternalProcessKeyRetriever
[04/Sep/2019:13:24:01][KeyRetrieverRunner-dd4ea812-c044-41c0-93bf-ec376c732c93]:
About to execute command: [/usr/libexec/ipa/ipa-pki-retrieve-key,
caSigningCert cert-pki-ca dd4ea812-c044-41c0-93bf-ec376c732c93,
man-fb-ipa-01.testhost.com]
[04/Sep/2019:13:24:02][KeyRetrieverRunner-dd4ea812-c044-41c0-93bf-ec376c732c93]:
Failed to retrieve key from any host.
[04/Sep/2019:13:24:02][KeyRetrieverRunner-dd4ea812-c044-41c0-93bf-ec376c732c93]:
KeyRetriever did not return a result.
[04/Sep/2019:13:24:02][KeyRetrieverRunner-dd4ea812-c044-41c0-93bf-ec376c732c93]:
Retrying in 1946 seconds
I'm presuming this is the reason OCSP is failing as it can't sign the response
for the subCA?
Does anyone know if this is a known issue or if there is something I need to
modify to get the OCSP working on the replica host?
Any help would be greatly appreciated
Thanks
Dave
See logs below.
2nd IPA Replica (Broken) /var/log/pki/pki-tomcat/ca/debug
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet:service() uri
= /ca/ocsp
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet: caOCSP start
to service.
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: IP: 10.128.164.2
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet: no
authMgrName
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]:
CMSServlet.authorize(DirAclAuthz)
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet: in
auditSubjectID
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet:
auditSubjectID auditContext {locale=en_GB, ipAddress=10.128.164.2}
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet
auditSubjectID: subjectID: null
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet: in
auditGroupID
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet: auditGroupID
auditContext {locale=en_GB, ipAddress=10.128.164.2}
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet auditGroupID:
groupID: null
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: In
LdapBoundConnFactory::getConn()
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: masterConn is connected:
true
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: getConn: conn is
connected true
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: getConn: mNumConns now 2
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: returnConn: mNumConns
now 3
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]:
AAclAuthz.checkPermission(certServer.ee.request.ocsp, submit)
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: checkAllowEntries():
expressions: ipaddress=".*"
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: evaluating expressions:
ipaddress=".*"
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: evaluated expression:
ipaddress=".*" to be true
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: DirAclAuthz:
authorization passed
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: SignedAuditLogger: event
AUTHZ
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: OCSPServlet: Servlet
Path: /ocsp
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: OCSPServlet: RequestURI:
/ca/ocsp
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: OCSPServlet: PathInfo:
null
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: OCSPServlet: HTTP
method: POST
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: OCSPServlet: processing
POST request
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: OCSPServlet: decoding
request
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: OCSPServlet: validating
request
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: In
LdapBoundConnFactory::getConn()
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: masterConn is connected:
true
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: getConn: conn is
connected true
[04/Sep/2019:12:25:13][ajp-bio-127.0.0.1-8009-exec-1]: getConn: mNumConns now 2
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: returnConn: mNumConns
now 3
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: In
LdapBoundConnFactory::getConn()
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: masterConn is connected:
true
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: getConn: conn is
connected true
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: getConn: mNumConns now 2
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: returnConn: mNumConns
now 3
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: CertificateAuthority:
validating OCSP request
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: CertificateAuthority:
processing request for cert 0x1b
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: In
LdapBoundConnFactory::getConn()
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: masterConn is connected:
true
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: getConn: conn is
connected true
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: getConn: mNumConns now 2
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: returnConn: mNumConns
now 3
java.lang.NullPointerException
at
com.netscape.ca.CertificateAuthority.getResponderIDByName(CertificateAuthority.java:2340)
at
com.netscape.ca.CertificateAuthority.validate(CertificateAuthority.java:2473)
at
com.netscape.ca.CertificateAuthority.validate(CertificateAuthority.java:2428)
at
com.netscape.cms.servlet.ocsp.OCSPServlet.process(OCSPServlet.java:222)
at com.netscape.cms.servlet.base.CMSServlet.service(CMSServlet.java:493)
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:218)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:506)
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:962)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)
at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:190)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
at
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet: in
auditSubjectID
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet:
auditSubjectID auditContext {locale=en_GB, ipAddress=10.128.164.2}
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet
auditSubjectID: subjectID: null
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: SignedAuditLogger: event
OCSP_GENERATION
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: OCSPServlet: response is
null
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet.java:
renderTemplate
[04/Sep/2019:12:25:14][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet: curDate=Wed
Sep 04 12:25:14 BST 2019 id=caOCSP time=213
If I look at 1st IPA server which is working I see
1st IPA Master (Working) /var/log/pki/pki-tomcat/ca/debug
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CMSServlet:service()
uri = /ca/ocsp
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CMSServlet: caOCSP
start to service.
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: IP: 10.128.167.2
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CMSServlet: no
authMgrName
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]:
CMSServlet.authorize(DirAclAuthz)
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CMSServlet: in
auditSubjectID
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CMSServlet:
auditSubjectID auditContext {locale=en_GB, ipAddress=10.128.167.2}
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CMSServlet
auditSubjectID: subjectID: null
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CMSServlet: in
auditGroupID
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CMSServlet:
auditGroupID auditContext {locale=en_GB, ipAddress=10.128.167.2}
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CMSServlet
auditGroupID: groupID: null
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: In
LdapBoundConnFactory::getConn()
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: masterConn is
connected: true
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: getConn: conn is
connected true
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: getConn: mNumConns now 2
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: returnConn: mNumConns
now 3
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]:
AAclAuthz.checkPermission(certServer.ee.request.ocsp, submit)
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: checkAllowEntries():
expressions: ipaddress=".*"
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: evaluating expressions:
ipaddress=".*"
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: evaluated expression:
ipaddress=".*" to be true
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: DirAclAuthz:
authorization passed
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: SignedAuditLogger:
event AUTHZ
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: OCSPServlet: Servlet
Path: /ocsp
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: OCSPServlet:
RequestURI: /ca/ocsp
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: OCSPServlet: PathInfo:
null
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: OCSPServlet: HTTP
method: POST
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: OCSPServlet: processing
POST request
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: OCSPServlet: decoding
request
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: OCSPServlet: validating
request
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: In
LdapBoundConnFactory::getConn()
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: masterConn is
connected: true
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: getConn: conn is
connected true
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: getConn: mNumConns now 4
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: returnConn: mNumConns
now 5
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: In
LdapBoundConnFactory::getConn()
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: masterConn is
connected: true
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: getConn: conn is
connected true
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: getConn: mNumConns now 4
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: returnConn: mNumConns
now 5
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CertificateAuthority:
validating OCSP request
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CertificateAuthority:
processing request for cert 0x1b
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: In
LdapBoundConnFactory::getConn()
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: masterConn is
connected: true
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: getConn: conn is
connected true
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: getConn: mNumConns now 4
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: returnConn: mNumConns
now 5
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: adding signature
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: Getting algorithm
context for SHA256withRSA RSASignatureWithSHA256Digest
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: Signing Certificate
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CMSServlet: in
auditSubjectID
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CMSServlet:
auditSubjectID auditContext {locale=en_GB, ipAddress=10.128.167.2}
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: CMSServlet
auditSubjectID: subjectID: null
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: SignedAuditLogger:
event OCSP_GENERATION
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: OCSPServlet: OCSP
Request:
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: OCSPServlet:
MGwwaqADAgEAMD4wPDA6MAkGBSsOAwIaBQAEFK377uGJz9Owh8lyIT07pU1YHAEs^M
BBTDA9mf27XJPVL0EOy+SaFKAxCZhAIBG6IjMCEwHwYJKwYBBQUHMAECBBIEEJMj^M
ZAn0Vjd91e0eZdmHXyo=^M
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: Serial Number: 27
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: OCSPServlet: OCSP
Response Size:
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: OCSPServlet: 2364
[04/Sep/2019:13:22:06][ajp-bio-127.0.0.1-8009-exec-15]: OCSPServlet: OCSP
Response Data:
**SNIP**
_______________________________________________
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org
Fedora Code of Conduct:
https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives:
https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org
