#1358 Retrying failed OCSP clone results duplicate replecation id and a failure.
Closed: Duplicate None Opened 8 years ago by jmagne.

During work on a ticket to diagnose an issue with creating a clone of an OCSP using pkispawn, this problem was discovered as follows:

  1. Create the master ca and ocsp on a host.

  2. On the same host create a clone of the ocsp after creating another directory server instance to hold the data for all the clones.

  3. This failed due to another ticket as described.

  4. Used pkidestroy to dispose of the aborted ocsp clone instance attempt.

  5. Re-ran the same pkispawn test, using the exact same install cfg file to re-attempt the clone with the exact same parameters.

This operation failed earlier than the previous test due to a different case. This time it failed because the cloned OCSP's debug log is reporting a problem with negotiating the various replication agreement steps.

The part of the log showing this in the cloned OCSP is as follows:

[29/Apr/2015:10:38:29]http-bio-22443-exec-3: DatabasePanel setupReplication: replicadn=cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config
[29/Apr/2015:10:38:29]http-bio-22443-exec-3: createReplicationManager: containing ou already exists
[29/Apr/2015:10:38:29]http-bio-22443-exec-3: createReplicationManager: Replication Manager has already used
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: createReplicationManager: containing ou already exists
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: createReplicationManager: Replication Manager has already used
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: getInstanceDir: DN for storing nsslapd-directory: cn=config,cn=ldbm database,cn=plugins,cn=config
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: getInstanceDir: attribute name: nsslapd-directory
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: getInstanceDir: instanceDir=/var/lib/dirsrv/slapd-localhost/db
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: createChangeLog: Changelog entry has already used
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: getInstanceDir: DN for storing nsslapd-directory: cn=config,cn=ldbm database,cn=plugins,cn=config
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: getInstanceDir: attribute name: nsslapd-directory
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: getInstanceDir: instanceDir=/var/lib/dirsrv/slapd-localhost-clone/db
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: createChangeLog: Changelog entry has already used
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: enableReplication: replicadn: cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: enableReplication: cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config has already been used
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: enableReplication: Failed to modify cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config entry. Exception: netscape.ldap.LDAPException: error result (68)
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: enableReplication: replicadn: cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: enableReplication: Successfully create cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config entry.
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: setupReplication: Finished enabling replication
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: createReplicationAgreement: dn: cn=masterAgreement1-localhost.localdomain-pki-clone,cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: About to set description attr to masterAgreement1-localhost.localdomain-pki-clone
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: createReplicationAgreement: cn=masterAgreement1-localhost.localdomain-pki-clone,cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config has already used
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: createReplicationAgreement: Successfully create replication agreement masterAgreement1-localhost.localdomain-pki-clone
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: createReplicationAgreement: dn: cn=cloneAgreement1-localhost.localdomain-pki-clone,cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: About to set description attr to cloneAgreement1-localhost.localdomain-pki-clone
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: createReplicationAgreement: Successfully create replication agreement cloneAgreement1-localhost.localdomain-pki-clone
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: initializeConsumer: initializeConsumer dn: cn=masterAgreement1-localhost.localdomain-pki-clone,cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: initializeConsumer: initializeConsumer host: localhost.localdomain port: 389
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: initializeConsumer: Successfully initialized consumer
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: replicationDone: dn: cn=masterAgreement1-localhost.localdomain-pki-clone,cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config
[29/Apr/2015:10:38:30]http-bio-22443-exec-3: setupReplication: Waiting for replication to complete
[29/Apr/2015:10:38:31]http-bio-22443-exec-3: replicationDone: dn: cn=masterAgreement1-localhost.localdomain-pki-clone,cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config
[29/Apr/2015:10:38:31]http-bio-22443-exec-3: replicationStatus: dn: cn=masterAgreement1-localhost.localdomain-pki-clone,cn=replica,cn="o=pki-tomcat-OCSP",cn=mapping tree,cn=config
[29/Apr/2015:10:38:31]http-bio-22443-exec-3: setupReplication: consumer initialization failed. 11 Replication error acquiring replica: duplicate replica ID detected
[29/Apr/2015:10:38:31]http-bio-22443-exec-3: setupReplication: java.io.IOException: consumer initialization failed. 11 Replication error acquiring replica: duplicate replica ID detected
com.netscape.certsrv.base.PKIException: Error in populating database: java.io.IOException: Failed to setup the replication for cloning.
at org.dogtagpki.server.rest.SystemConfigService.initializeDatabase(SystemConfigService.java:733)
at org.dogtagpki.server.rest.SystemConfigService.configure(SystemConfigService.java:179)
at org.dogtagpki.server.rest.SystemConfigService.configure(SystemConfigService.java:128)
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:483)
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:727)
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:483)
at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:277)
at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:274)
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:309)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:169)
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:483)
at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:277)
at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:274)
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:309)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:249)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:238)
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:221)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:501)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1040)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:314)
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: java.io.IOException: Failed to setup the replication for cloning.
at com.netscape.cms.servlet.csadmin.ConfigurationUtils.setupReplication(ConfigurationUtils.java:1953)
at org.dogtagpki.server.rest.SystemConfigService.initializeDatabase(SystemConfigService.java:724)
... 64 more
Caused by: java.io.IOException: consumer initialization failed. 11 Replication error acquiring replica: duplicate replica ID detected
at com.netscape.cms.servlet.csadmin.ConfigurationUtils.setupReplication(ConfigurationUtils.java:1941)
... 65 more


OCSP clone cfg file. OCSP master was created with interactive method.
ocspclone.cfg

Per CS/DS meeting of 05/04/2015: 10.2.4

Per CS/DS meeting of 06/08/2015: 10.2.6

This also occurs when you attempt to create multiple OCSP clones. The problem seems to be that we don't use replica ID ranges like we do with the CA and KRA.

Took a quick shot at this by updating the OCSP's config to have the replica id range settings included.

This did not work due to the fact that there is some code in the java configuration classes that is checking to see if the subsystem is a kra or ca before processing those entries. The code checks for a kra or ca and then does a block where it updates the replica id range AND the serial number AND request range.

This is skipped for OCSP since I"m not sure the OCSP even has any of this data.

I think the replica id stuff will have to be retrofitted to OCSP for this to work. This will take more investigation to best determine a course of action..

Checkin for man page, that states we don't support OCSP cloning for now:

165ae515656dd7b9a01b0a97cced0811fea6f148

Actual checkin for above is this hash:

19f6109f4e5ca68561ae00997fc959b8a228787b

Metadata Update from @jmagne:
- Issue set to the milestone: 10.2.6

7 years ago

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/1920

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.

Login to comment on this ticket.

Metadata