Details
Description
Issue Summary
Active Directory incremental sync fails with duplicate key error.
Steps to Reproduce
- Use MS AD directory
- Incremental synchronisation enabled
- New user added to AD
- New user has a membership to a group present in AD
- Start incremental synchronisation
Expected Results
Synchronisation completes without errors.
Actual Results
Synchronisation completes successfully but the below exception is thrown:
2020-05-04 15:55:33,836 ERROR [Caesium-1-4] o.h.e.j.batch.internal.BatchingBatch HHH000315: Exception executing batch [java.sql.BatchUpdateException: Batch entry 0 insert into cwd_membership (parent_id, child_id, membership_type, group_type, parent_name, lower_parent_name, child_name, lower_child_name, created_date, directory_id, id) values (7244102, 8323074, 'GROUP_USER', 'GROUP', 'employees-guests', 'employees-guests', 'alex', 'alex', '2020-05-04 15:55:33.832+02', 7340033, 8257747) was aborted: ERROR: duplicate key value violates unique constraint "sys_idx_sys_ct_10168_10170" Detail: Key (parent_id, child_id, membership_type)=(7244102, 8323074, GROUP_USER) already exists. Call getNextException to see other errors in the batch.], SQL: insert into cwd_membership (parent_id, child_id, membership_type, group_type, parent_name, lower_parent_name, child_name, lower_child_name, created_date, directory_id, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) 2020-05-04 15:55:33,837 WARN [Caesium-1-4] o.h.e.jdbc.spi.SqlExceptionHelper SQL Error: 0, SQLState: 23505 2020-05-04 15:55:33,837 ERROR [Caesium-1-4] o.h.e.jdbc.spi.SqlExceptionHelper Batch entry 0 insert into cwd_membership (parent_id, child_id, membership_type, group_type, parent_name, lower_parent_name, child_name, lower_child_name, created_date, directory_id, id) values (7244102, 8323074, 'GROUP_USER', 'GROUP', 'employees-guests', 'employees-guests', 'alex', 'alex', '2020-05-04 15:55:33.832+02', 7340033, 8257747) was aborted: ERROR: duplicate key value violates unique constraint "sys_idx_sys_ct_10168_10170" Detail: Key (parent_id, child_id, membership_type)=(7244102, 8323074, GROUP_USER) already exists. Call getNextException to see other errors in the batch. 2020-05-04 15:55:33,837 ERROR [Caesium-1-4] o.h.e.jdbc.spi.SqlExceptionHelper ERROR: duplicate key value violates unique constraint "sys_idx_sys_ct_10168_10170" Detail: Key (parent_id, child_id, membership_type)=(7244102, 8323074, GROUP_USER) already exists. 2020-05-04 15:55:33,872 WARN [Caesium-1-4] c.a.c.u.p.h.b.h.Hibernate5StatelessSessionBatchProcessor batch failed falling back to individual processing org.hibernate.exception.ConstraintViolationException: could not execute batch at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:109) at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113) at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:129) at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:105) at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.execute(AbstractBatchImpl.java:148) at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.executeBatch(JdbcCoordinatorImpl.java:198) at org.hibernate.internal.StatelessSessionImpl.managedFlush(StatelessSessionImpl.java:415) at org.hibernate.internal.StatelessSessionImpl.flushBeforeTransactionCompletion(StatelessSessionImpl.java:780) at org.hibernate.internal.StatelessSessionImpl.beforeTransactionCompletion(StatelessSessionImpl.java:750) at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:447) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:183) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:40) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:281) at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:101) at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate5.AbstractHibernateBatchProcessor.commitTransaction(AbstractHibernateBatchProcessor.java:64) at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate5.AbstractHibernateBatchProcessor.afterProcessBatch(AbstractHibernateBatchProcessor.java:18) at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.processBatch(AbstractBatchProcessor.java:166) at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.execute(AbstractBatchProcessor.java:133) at com.atlassian.crowd.dao.membership.MembershipDAOHibernate.addAll(MembershipDAOHibernate.java:57) at com.atlassian.crowd.dao.membership.MembershipDAOHibernate.addAllUsersToGroup(MembershipDAOHibernate.java:80) at jdk.internal.reflect.GeneratedMethodAccessor1709.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at com.atlassian.crowd.directory.CachingDirectory.addAllUsersToGroup(CachingDirectory.java:136) at com.atlassian.crowd.directory.DbCachingRemoteChangeOperations.addUserMembershipsForGroup(DbCachingRemoteChangeOperations.java:745) at jdk.internal.reflect.GeneratedMethodAccessor873.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at com.atlassian.crowd.directory.DirectoryCacheImplUsingChangeOperations.syncUserMembersForGroup(DirectoryCacheImplUsingChangeOperations.java:116) at com.atlassian.crowd.directory.synchronisation.cache.AbstractCacheRefresher.synchroniseMemberships(AbstractCacheRefresher.java:211) at com.atlassian.crowd.directory.synchronisation.cache.UsnChangedCacheRefresher.syncGroups(UsnChangedCacheRefresher.java:489) at com.atlassian.crowd.directory.synchronisation.cache.UsnChangedCacheRefresher.synchroniseGroupChanges(UsnChangedCacheRefresher.java:401) at com.atlassian.crowd.directory.synchronisation.cache.UsnChangedCacheRefresher.synchroniseChanges(UsnChangedCacheRefresher.java:127) at com.atlassian.crowd.directory.DbCachingRemoteDirectory.synchroniseCache(DbCachingRemoteDirectory.java:1026) at com.atlassian.crowd.manager.directory.DirectorySynchroniserImpl.lambda$synchronise$0(DirectorySynchroniserImpl.java:80) at com.atlassian.crowd.audit.NoOpAuditLogContext.withAuditLogSource(NoOpAuditLogContext.java:17) at com.atlassian.crowd.manager.directory.DirectorySynchroniserImpl.synchronise(DirectorySynchroniserImpl.java:78) at jdk.internal.reflect.GeneratedMethodAccessor1643.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at com.atlassian.crowd.directory.DbCachingDirectoryPoller.pollChanges(DbCachingDirectoryPoller.java:45) at com.atlassian.crowd.manager.directory.monitor.poller.DirectoryPollerJobRunner.runJob(DirectoryPollerJobRunner.java:92) at com.atlassian.scheduler.core.JobLauncher.runJob(JobLauncher.java:134) at com.atlassian.scheduler.core.JobLauncher.launchAndBuildResponse(JobLauncher.java:106) at com.atlassian.scheduler.core.JobLauncher.launch(JobLauncher.java:90) at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService.launchJob(CaesiumSchedulerService.java:435) at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService.executeClusteredJob(CaesiumSchedulerService.java:430) at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService.executeClusteredJobWithRecoveryGuard(CaesiumSchedulerService.java:454) at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService.executeQueuedJob(CaesiumSchedulerService.java:382) at com.atlassian.scheduler.caesium.impl.SchedulerQueueWorker.executeJob(SchedulerQueueWorker.java:66) at com.atlassian.scheduler.caesium.impl.SchedulerQueueWorker.executeNextJob(SchedulerQueueWorker.java:60) at com.atlassian.scheduler.caesium.impl.SchedulerQueueWorker.run(SchedulerQueueWorker.java:35) at java.base/java.lang.Thread.run(Thread.java:834) ... 29 frames trimmed Caused by: java.sql.BatchUpdateException: Batch entry 0 insert into cwd_membership (parent_id, child_id, membership_type, group_type, parent_name, lower_parent_name, child_name, lower_child_name, created_date, directory_id, id) values (7244102, 8323074, 'GROUP_USER', 'GROUP', 'employees-guests', 'employees-guests', 'alex', 'alex', '2020-05-04 15:55:33.832+02', 7340033, 8257747) was aborted: ERROR: duplicate key value violates unique constraint "sys_idx_sys_ct_10168_10170" Detail: Key (parent_id, child_id, membership_type)=(7244102, 8323074, GROUP_USER) already exists. Call getNextException to see other errors in the batch. at org.postgresql.jdbc.BatchResultHandler.handleError(BatchResultHandler.java:154) at org.postgresql.core.ResultHandlerDelegate.handleError(ResultHandlerDelegate.java:50) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2269) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:511) at org.postgresql.jdbc.PgStatement.internalExecuteBatch(PgStatement.java:851) at org.postgresql.jdbc.PgStatement.executeBatch(PgStatement.java:874) at org.postgresql.jdbc.PgPreparedStatement.executeBatch(PgPreparedStatement.java:1569) at com.zaxxer.hikari.pool.ProxyStatement.executeBatch(ProxyStatement.java:128) at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeBatch(HikariProxyPreparedStatement.java) at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:119) ... 48 common frames omitted Next exception: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "sys_idx_sys_ct_10168_10170" Detail: Key (parent_id, child_id, membership_type)=(7244102, 8323074, GROUP_USER) already exists. at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2533) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2268) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:511) at org.postgresql.jdbc.PgStatement.internalExecuteBatch(PgStatement.java:851) at org.postgresql.jdbc.PgStatement.executeBatch(PgStatement.java:874) at org.postgresql.jdbc.PgPreparedStatement.executeBatch(PgPreparedStatement.java:1569) at com.zaxxer.hikari.pool.ProxyStatement.executeBatch(ProxyStatement.java:128) at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeBatch(HikariProxyPreparedStatement.java) at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:119) at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:105) at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.execute(AbstractBatchImpl.java:148) at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.executeBatch(JdbcCoordinatorImpl.java:198) at org.hibernate.internal.StatelessSessionImpl.managedFlush(StatelessSessionImpl.java:415) at org.hibernate.internal.StatelessSessionImpl.flushBeforeTransactionCompletion(StatelessSessionImpl.java:780) at org.hibernate.internal.StatelessSessionImpl.beforeTransactionCompletion(StatelessSessionImpl.java:750) at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:447) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:183) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:40) at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:281) at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:101) at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate5.AbstractHibernateBatchProcessor.commitTransaction(AbstractHibernateBatchProcessor.java:64) at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate5.AbstractHibernateBatchProcessor.afterProcessBatch(AbstractHibernateBatchProcessor.java:18) at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.processBatch(AbstractBatchProcessor.java:166) at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.execute(AbstractBatchProcessor.java:133) at com.atlassian.crowd.dao.membership.MembershipDAOHibernate.addAll(MembershipDAOHibernate.java:57) at com.atlassian.crowd.dao.membership.MembershipDAOHibernate.addAllUsersToGroup(MembershipDAOHibernate.java:80) at jdk.internal.reflect.GeneratedMethodAccessor1709.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:366) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:99) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) at com.sun.proxy.$Proxy213.addAllUsersToGroup(Unknown Source) at com.atlassian.crowd.directory.CachingDirectory.addAllUsersToGroup(CachingDirectory.java:136) at com.atlassian.crowd.directory.DbCachingRemoteChangeOperations.addUserMembershipsForGroup(DbCachingRemoteChangeOperations.java:745) at jdk.internal.reflect.GeneratedMethodAccessor873.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:366) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:99) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) at com.sun.proxy.$Proxy1931.addUserMembershipsForGroup(Unknown Source) at com.atlassian.crowd.directory.DirectoryCacheImplUsingChangeOperations.syncUserMembersForGroup(DirectoryCacheImplUsingChangeOperations.java:116) at com.atlassian.crowd.directory.synchronisation.cache.AbstractCacheRefresher.synchroniseMemberships(AbstractCacheRefresher.java:211) at com.atlassian.crowd.directory.synchronisation.cache.UsnChangedCacheRefresher.syncGroups(UsnChangedCacheRefresher.java:489) at com.atlassian.crowd.directory.synchronisation.cache.UsnChangedCacheRefresher.synchroniseGroupChanges(UsnChangedCacheRefresher.java:401) at com.atlassian.crowd.directory.synchronisation.cache.UsnChangedCacheRefresher.synchroniseChanges(UsnChangedCacheRefresher.java:127) at com.atlassian.crowd.directory.DbCachingRemoteDirectory.synchroniseCache(DbCachingRemoteDirectory.java:1026) at com.atlassian.crowd.manager.directory.DirectorySynchroniserImpl.lambda$synchronise$0(DirectorySynchroniserImpl.java:80) at com.atlassian.crowd.audit.NoOpAuditLogContext.withAuditLogSource(NoOpAuditLogContext.java:17) at com.atlassian.crowd.manager.directory.DirectorySynchroniserImpl.synchronise(DirectorySynchroniserImpl.java:78) at jdk.internal.reflect.GeneratedMethodAccessor1643.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:366) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:99) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) at com.sun.proxy.$Proxy237.synchronise(Unknown Source) at com.atlassian.crowd.directory.DbCachingDirectoryPoller.pollChanges(DbCachingDirectoryPoller.java:45) at com.atlassian.crowd.manager.directory.monitor.poller.DirectoryPollerJobRunner.runJob(DirectoryPollerJobRunner.java:92) at com.atlassian.scheduler.core.JobLauncher.runJob(JobLauncher.java:134) at com.atlassian.scheduler.core.JobLauncher.launchAndBuildResponse(JobLauncher.java:106) at com.atlassian.scheduler.core.JobLauncher.launch(JobLauncher.java:90) at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService.launchJob(CaesiumSchedulerService.java:435) at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService.executeClusteredJob(CaesiumSchedulerService.java:430) at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService.executeClusteredJobWithRecoveryGuard(CaesiumSchedulerService.java:454) at com.atlassian.scheduler.caesium.impl.CaesiumSchedulerService.executeQueuedJob(CaesiumSchedulerService.java:382) at com.atlassian.scheduler.caesium.impl.SchedulerQueueWorker.executeJob(SchedulerQueueWorker.java:66) at com.atlassian.scheduler.caesium.impl.SchedulerQueueWorker.executeNextJob(SchedulerQueueWorker.java:60) at com.atlassian.scheduler.caesium.impl.SchedulerQueueWorker.run(SchedulerQueueWorker.java:35) at java.base/java.lang.Thread.run(Thread.java:834) Caused by: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "sys_idx_sys_ct_10168_10170" Detail: Key (parent_id, child_id, membership_type)=(7244102, 8323074, GROUP_USER) already exists. at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2533) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2268) ... 55 common frames omitted
Workaround
There is no functional problem - this is just a logging issue. There is currently no way to avoid the error in the logs.