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@lists.fedorahosted.org