Uploaded image for project: 'OpenIDM'
  1. OpenIDM
  2. OPENIDM-9152

Backport OPENIDM-7894: Clustered recon may fail

    Details

      Description

      When run clustered recon with two nodes or three nodes, the recon is not always successful. With 100K users in DJ, recon from DJ to managed may see results like:

      Mar 13, 2017 6:20:21 PM org.forgerock.openidm.sync.impl.ObjectMapping logReconEnd
      INFO: Reconciliation failed. SOURCE_IGNORED: 0 FOUND_ALREADY_LINKED: 0 UNQUALIFIED: 0 ABSENT: 85000 TARGET_IGNORED: 0 MISSING: 0 ALL_GONE: 0 UNASSIGNED: 0 AMBIGUOUS: 0 CONFIRMED: 0 LINK_ONLY: 0 SOURCE_MISSING: 0 FOUND: 0
      

      When it happens, IDM log file has error like this(complete log files are attached from two nodes cluster):

      Mar 13, 2017 6:20:21 PM org.forgerock.openidm.scheduler.JobRequestHandler addSchedule
      WARNING: Failed to create scheduler service for clustered_recon-e2e05271-6b08-4b83-9ec4-119c528b5812-26-sourcePage-AG91PXBlb3BsZQB1aWQ9ci1rLTY2MTE=:0: Error storing trigger
      org.quartz.JobPersistenceException: Error storing trigger [See nested exception: org.forgerock.json.resource.PreconditionFailedException: Update rejected as current Object revision 169 is different than expected by caller (168), the object has changed since retrieval.]
        at org.forgerock.openidm.quartz.impl.RepoJobStore.storeTrigger(RepoJobStore.java:482)
        at org.forgerock.openidm.quartz.impl.RepoJobStore.storeJobAndTrigger(RepoJobStore.java:430)
        at org.quartz.core.QuartzScheduler.scheduleJob(QuartzScheduler.java:822)
        at org.quartz.impl.StdScheduler.scheduleJob(StdScheduler.java:243)
        at org.forgerock.openidm.scheduler.AbstractScheduler.scheduleJob(AbstractScheduler.java:90)
        at org.forgerock.openidm.scheduler.PersistedScheduler.scheduleJob(PersistedScheduler.java:27)
        at org.forgerock.openidm.scheduler.JobRequestHandler.addSchedule(JobRequestHandler.java:410)
        at org.forgerock.openidm.scheduler.JobRequestHandler.handleCreate(JobRequestHandler.java:149)
        at org.forgerock.json.resource.Router.handleCreate(Router.java:264)
        at org.forgerock.openidm.scheduler.SchedulerService.handleCreate(SchedulerService.java:308)
        at org.forgerock.json.resource.Router.handleCreate(Router.java:264)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:65)
        at org.forgerock.json.resource.Filters$ConditionalFilter.filterCreate(Filters.java:54)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.json.resource.Filters$ConditionalFilter.filterCreate(Filters.java:54)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.json.resource.Filters$ConditionalFilter.filterCreate(Filters.java:54)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.openidm.audit.filter.AuditFilter$2.apply(AuditFilter.java:142)
        at org.forgerock.openidm.audit.filter.AuditFilter$2.apply(AuditFilter.java:139)
        at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:247)
        at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:236)
        at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:215)
        at org.forgerock.openidm.audit.filter.AuditFilter.logAuditAccessEntry(AuditFilter.java:247)
        at org.forgerock.openidm.audit.filter.AuditFilter.filterCreate(AuditFilter.java:138)
        at org.forgerock.openidm.filter.MutableFilterDecorator.filterCreate(MutableFilterDecorator.java:72)
        at org.forgerock.json.resource.Filters$ConditionalFilter.filterCreate(Filters.java:52)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.openidm.servlet.internal.ServletConnectionFactory$4.filterCreate(ServletConnectionFactory.java:441)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.openidm.filter.PassthroughFilter.filterCreate(PassthroughFilter.java:48)
        at org.forgerock.openidm.filter.MutableFilterDecorator.filterCreate(MutableFilterDecorator.java:72)
        at org.forgerock.openidm.filter.MutableFilterDecorator.filterCreate(MutableFilterDecorator.java:72)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.openidm.filter.PassthroughFilter.filterCreate(PassthroughFilter.java:48)
        at org.forgerock.openidm.filter.MutableFilterDecorator.filterCreate(MutableFilterDecorator.java:72)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.json.resource.FilterChain.handleCreate(FilterChain.java:228)
        at org.forgerock.json.resource.InternalConnection.createAsync(InternalConnection.java:40)
        at org.forgerock.json.resource.AbstractAsynchronousConnection.create(AbstractAsynchronousConnection.java:42)
        at org.forgerock.json.resource.AbstractConnectionWrapper.create(AbstractConnectionWrapper.java:92)
        at org.forgerock.openidm.servlet.internal.ServletConnectionFactory$1$1.create(ServletConnectionFactory.java:215)
        at org.forgerock.json.resource.AbstractConnectionWrapper.create(AbstractConnectionWrapper.java:92)
        at org.forgerock.openidm.sync.impl.cluster.SchedulerClusteredReconJobDispatch.scheduleClusteredReconJob(SchedulerClusteredReconJobDispatch.java:119)
        at org.forgerock.openidm.sync.impl.cluster.SchedulerClusteredReconJobDispatch.dispatchSourcePageRecon(SchedulerClusteredReconJobDispatch.java:72)
        at org.forgerock.openidm.sync.impl.ClusteredRecon.optionallyScheduleNextSourcePage(ClusteredRecon.java:206)
        at org.forgerock.openidm.sync.impl.ClusteredRecon.reconSourcePageCommonActions(ClusteredRecon.java:173)
        at org.forgerock.openidm.sync.impl.ClusteredRecon.clusteredReconNextSourcePage(ClusteredRecon.java:157)
        at org.forgerock.openidm.sync.impl.ClusteredRecon.dispatchClusteredRecon(ClusteredRecon.java:66)
        at org.forgerock.openidm.sync.impl.ObjectMapping.recon(ObjectMapping.java:715)
        at org.forgerock.openidm.sync.impl.ReconciliationService.reconcile(ReconciliationService.java:423)
        at org.forgerock.openidm.sync.impl.ReconciliationService.reconcile(ReconciliationService.java:370)
        at org.forgerock.openidm.sync.impl.SynchronizationService.execute(SynchronizationService.java:303)
        at org.forgerock.openidm.quartz.impl.SchedulerServiceJob.execute(SchedulerServiceJob.java:127)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:223)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:549)
      Caused by: org.forgerock.json.resource.PreconditionFailedException: Update rejected as current Object revision 169 is different than expected by caller (168), the object has changed since retrieval.
        at org.forgerock.openidm.repo.jdbc.impl.GenericTableHandler.update(GenericTableHandler.java:522)
        at org.forgerock.openidm.repo.jdbc.impl.JDBCRepoService.update(JDBCRepoService.java:416)
        at org.forgerock.openidm.quartz.impl.RepoJobStore.storeTrigger(RepoJobStore.java:472)
        ... 55 more
      
      Mar 13, 2017 6:20:21 PM org.forgerock.openidm.servlet.internal.ServletConnectionFactory$3 handleException
      WARNING: Resource exception: 500 Internal Server Error: "Error storing trigger"
      org.forgerock.json.resource.InternalServerErrorException: Error storing trigger
        at org.forgerock.openidm.scheduler.JobRequestHandler.handleCreate(JobRequestHandler.java:157)
        at org.forgerock.json.resource.Router.handleCreate(Router.java:264)
        at org.forgerock.openidm.scheduler.SchedulerService.handleCreate(SchedulerService.java:308)
        at org.forgerock.json.resource.Router.handleCreate(Router.java:264)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:65)
        at org.forgerock.json.resource.Filters$ConditionalFilter.filterCreate(Filters.java:54)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.json.resource.Filters$ConditionalFilter.filterCreate(Filters.java:54)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.json.resource.Filters$ConditionalFilter.filterCreate(Filters.java:54)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.openidm.audit.filter.AuditFilter$2.apply(AuditFilter.java:142)
        at org.forgerock.openidm.audit.filter.AuditFilter$2.apply(AuditFilter.java:139)
        at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:247)
        at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:236)
        at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:215)
        at org.forgerock.openidm.audit.filter.AuditFilter.logAuditAccessEntry(AuditFilter.java:247)
        at org.forgerock.openidm.audit.filter.AuditFilter.filterCreate(AuditFilter.java:138)
        at org.forgerock.openidm.filter.MutableFilterDecorator.filterCreate(MutableFilterDecorator.java:72)
        at org.forgerock.json.resource.Filters$ConditionalFilter.filterCreate(Filters.java:52)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.openidm.servlet.internal.ServletConnectionFactory$4.filterCreate(ServletConnectionFactory.java:441)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.openidm.filter.PassthroughFilter.filterCreate(PassthroughFilter.java:48)
        at org.forgerock.openidm.filter.MutableFilterDecorator.filterCreate(MutableFilterDecorator.java:72)
        at org.forgerock.openidm.filter.MutableFilterDecorator.filterCreate(MutableFilterDecorator.java:72)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.openidm.filter.PassthroughFilter.filterCreate(PassthroughFilter.java:48)
        at org.forgerock.openidm.filter.MutableFilterDecorator.filterCreate(MutableFilterDecorator.java:72)
        at org.forgerock.json.resource.FilterChain$Cursor.handleCreate(FilterChain.java:63)
        at org.forgerock.json.resource.FilterChain.handleCreate(FilterChain.java:228)
        at org.forgerock.json.resource.InternalConnection.createAsync(InternalConnection.java:40)
        at org.forgerock.json.resource.AbstractAsynchronousConnection.create(AbstractAsynchronousConnection.java:42)
        at org.forgerock.json.resource.AbstractConnectionWrapper.create(AbstractConnectionWrapper.java:92)
        at org.forgerock.openidm.servlet.internal.ServletConnectionFactory$1$1.create(ServletConnectionFactory.java:215)
        at org.forgerock.json.resource.AbstractConnectionWrapper.create(AbstractConnectionWrapper.java:92)
        at org.forgerock.openidm.sync.impl.cluster.SchedulerClusteredReconJobDispatch.scheduleClusteredReconJob(SchedulerClusteredReconJobDispatch.java:119)
        at org.forgerock.openidm.sync.impl.cluster.SchedulerClusteredReconJobDispatch.dispatchSourcePageRecon(SchedulerClusteredReconJobDispatch.java:72)
        at org.forgerock.openidm.sync.impl.ClusteredRecon.optionallyScheduleNextSourcePage(ClusteredRecon.java:206)
        at org.forgerock.openidm.sync.impl.ClusteredRecon.reconSourcePageCommonActions(ClusteredRecon.java:173)
        at org.forgerock.openidm.sync.impl.ClusteredRecon.clusteredReconNextSourcePage(ClusteredRecon.java:157)
        at org.forgerock.openidm.sync.impl.ClusteredRecon.dispatchClusteredRecon(ClusteredRecon.java:66)
        at org.forgerock.openidm.sync.impl.ObjectMapping.recon(ObjectMapping.java:715)
        at org.forgerock.openidm.sync.impl.ReconciliationService.reconcile(ReconciliationService.java:423)
        at org.forgerock.openidm.sync.impl.ReconciliationService.reconcile(ReconciliationService.java:370)
        at org.forgerock.openidm.sync.impl.SynchronizationService.execute(SynchronizationService.java:303)
        at org.forgerock.openidm.quartz.impl.SchedulerServiceJob.execute(SchedulerServiceJob.java:127)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:223)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:549)
      Caused by: org.quartz.JobPersistenceException: Error storing trigger [See nested exception: org.forgerock.json.resource.PreconditionFailedException: Update rejected as current Object revision 169 is different than expected by caller (168), the object has changed since retrieval.]
        at org.forgerock.openidm.quartz.impl.RepoJobStore.storeTrigger(RepoJobStore.java:482)
        at org.forgerock.openidm.quartz.impl.RepoJobStore.storeJobAndTrigger(RepoJobStore.java:430)
        at org.quartz.core.QuartzScheduler.scheduleJob(QuartzScheduler.java:822)
        at org.quartz.impl.StdScheduler.scheduleJob(StdScheduler.java:243)
        at org.forgerock.openidm.scheduler.AbstractScheduler.scheduleJob(AbstractScheduler.java:90)
        at org.forgerock.openidm.scheduler.PersistedScheduler.scheduleJob(PersistedScheduler.java:27)
        at org.forgerock.openidm.scheduler.JobRequestHandler.addSchedule(JobRequestHandler.java:410)
        at org.forgerock.openidm.scheduler.JobRequestHandler.handleCreate(JobRequestHandler.java:149)
        ... 48 more
      Caused by: org.forgerock.json.resource.PreconditionFailedException: Update rejected as current Object revision 169 is different than expected by caller (168), the object has changed since retrieval.
        at org.forgerock.openidm.repo.jdbc.impl.GenericTableHandler.update(GenericTableHandler.java:522)
        at org.forgerock.openidm.repo.jdbc.impl.JDBCRepoService.update(JDBCRepoService.java:416)
        at org.forgerock.openidm.quartz.impl.RepoJobStore.storeTrigger(RepoJobStore.java:472)
        ... 55 more
      

      Note that the failure doesn't always occurs, for instance, a recon run from a three nodes cluster, the recon create was successful with 100K users, but recon update failed with the similar error.

      To reproduce:
      Run QA test job as below(Needs to config config.cfg for number of users in DJ, Repo and IDM version etc.):
      python -u run-pybot.py -c stress -i gatling -s idm.ReconLDAPToManUserInCluster OpenIDM

      and check IDM log file.
      The QA job Jenkins job can be accessed at
      http://jenkins-gnb.internal.forgerock.com:8080/job/IDM-5.5.0/job/IDM-5.5.0-Stress-Tests-Recon-System-Ldap-2Nodes-Cluster/

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                cgdrake Chris Drake
                Reporter:
                cgdrake Chris Drake
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: