[CWD-2431] AD Groups with same CN but unique sAMAccountName causes Crowd to sync for a long time/indefinitely

Type: Bug
Resolution: Fixed
Priority: Medium
Fix Version/s: 2.2.7
Affects Version/s: 2.2.2
Component/s: Caching
Labels:
None
Environment:

Crowd 2.2.2 + Active Directory + Postgres/MySQL

Bug Fix Policy:
View Atlassian Server bug fix policy

Although I reproduced this in Crowd, it probably affects JIRA/Confluence with embedded Crowd as well.

Steps to Reproduce

Create a group named "testgroup" in Active Directory in a particular OU
Create a nested OU within that OU
Within the nested OU, create a new group named "testgroup" but with different pre-Windows 2000 name
Make sure both groups have at least one member
Create a directory within Crowd so that all of the above are within sync scope
Sync the directory

In Postgres, no errors are displayed in atlassian-crowd.log, but the sync never ends.

In MySQL, the sync eventually ends but encounters errors similar to the following:

2011-04-29 16:32:53,066 scheduler_Worker-9 WARN [org.hibernate.util.JDBCExceptionReporter] SQL Error: 1205, SQLState: 41000
2011-04-29 16:32:53,067 scheduler_Worker-9 ERROR [org.hibernate.util.JDBCExceptionReporter] Lock wait timeout exceeded; try restarting transaction
2011-04-29 16:32:53,069 scheduler_Worker-9 ERROR [hibernate.event.def.AbstractFlushingEventListener] Could not synchronize database state with session
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update

and

2011-04-29 16:33:46,296 scheduler_Worker-9 ERROR [persistence.hibernate.batch.AbstractBatchProcessor] Could not process class com.atlassian.crowd.model.membership.InternalMembership: com.atlassian.crowd.model.membership.InternalMembership@49b3a360[parentId=917506,childId=884740,membershipType=GROUP_USER,groupType=GROUP,parentName=testgroup,lowerParentName=testgroup,childName=SpaceUser,lowerChildName=spaceuser,directoryId=851969]
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update

Log of the full sync in MySQL, for reference:

2011-04-29 16:31:59,159 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectory] full synchronisation for directory [ 851969 ] starting
2011-04-29 16:32:00,548 pool-3-thread-1 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 4 ] remote users in [ 1365ms ]
2011-04-29 16:32:01,089 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] scanning [ 4 ] users to add or update
2011-04-29 16:32:01,090 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] scanned and compared [ 4 ] users for update in DB cache in [ 14ms ]
2011-04-29 16:32:01,090 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] adding [ 4 ] users
2011-04-29 16:32:01,151 scheduler_Worker-9 INFO [persistence.hibernate.batch.AbstractBatchProcessor] processed batch [ 1 ] of [ 1 ] [ 100.0 % ]
2011-04-29 16:32:01,152 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] added [ 4 ] users in [ 62ms ]
2011-04-29 16:32:01,152 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] synchronised [ 4 ] users in [ 76ms ]
2011-04-29 16:32:01,154 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] scanned and compared [ 4 ] users for delete in DB cache in [ 2ms ]
2011-04-29 16:32:01,155 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] scanned for deleted users in [ 3ms ]
2011-04-29 16:32:01,247 pool-3-thread-2 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 3 ] remote groups in [ 2059ms ]
2011-04-29 16:32:01,247 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] scanning [ 3 ] groups to add or update
2011-04-29 16:32:01,257 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] scanned and compared [ 3 ] groups for update in DB cache in [ 9ms ]
2011-04-29 16:32:01,264 scheduler_Worker-9 INFO [persistence.hibernate.batch.AbstractBatchProcessor] processed batch [ 1 ] of [ 1 ] [ 100.0 % ]
2011-04-29 16:32:01,265 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] added [ 2 ] groups in [ 8ms ]
2011-04-29 16:32:01,266 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] synchronized [ 3 ] groups in [ 18ms ]
2011-04-29 16:32:01,269 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] scanned and compared [ 3 ] groups for delete in DB cache in [ 3ms ]
2011-04-29 16:32:01,269 scheduler_Worker-9 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 2 ] remote user-group memberships in [ 0ms ]
2011-04-29 16:32:01,269 scheduler_Worker-9 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 0 ] remote group-group memberships in [ 0ms ]
2011-04-29 16:32:01,295 scheduler_Worker-9 INFO [persistence.hibernate.batch.AbstractBatchProcessor] processed batch [ 1 ] of [ 1 ] [ 100.0 % ]
2011-04-29 16:32:01,296 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] added [ 2 ] user members to [ testgroup ] in [ 15ms ]
2011-04-29 16:32:01,301 scheduler_Worker-9 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 0 ] remote user-group memberships in [ 0ms ]
2011-04-29 16:32:01,301 scheduler_Worker-9 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 0 ] remote group-group memberships in [ 0ms ]
2011-04-29 16:32:01,310 scheduler_Worker-9 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 1 ] remote user-group memberships in [ 0ms ]
2011-04-29 16:32:01,310 scheduler_Worker-9 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 0 ] remote group-group memberships in [ 0ms ]
2011-04-29 16:32:01,323 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] removed [ 1 ] user members from [ testgroup ] in [ 10ms ]
2011-04-29 16:32:01,326 scheduler_Worker-9 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 2 ] remote user-group memberships in [ 0ms ]
2011-04-29 16:32:01,327 scheduler_Worker-9 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 0 ] remote group-group memberships in [ 0ms ]
2011-04-29 16:32:53,066 scheduler_Worker-9 WARN [org.hibernate.util.JDBCExceptionReporter] SQL Error: 1205, SQLState: 41000
2011-04-29 16:32:53,067 scheduler_Worker-9 ERROR [org.hibernate.util.JDBCExceptionReporter] Lock wait timeout exceeded; try restarting transaction
2011-04-29 16:32:53,069 scheduler_Worker-9 ERROR [hibernate.event.def.AbstractFlushingEventListener] Could not synchronize database state with session
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
	at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
	at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:253)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:237)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
	at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
	at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
	at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
	at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate3.Hibernate3BatchProcessor.flushSession(Hibernate3BatchProcessor.java:45)
	at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate3.Hibernate3BatchProcessor.commitTransaction(Hibernate3BatchProcessor.java:122)
	at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate3.Hibernate3BatchProcessor.afterProcessBatch(Hibernate3BatchProcessor.java:91)
	at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.processBatch(AbstractBatchProcessor.java:160)
	at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.execute(AbstractBatchProcessor.java:132)
	at com.atlassian.crowd.dao.membership.MembershipDAOHibernate.addAll(MembershipDAOHibernate.java:303)
	at com.atlassian.crowd.dao.membership.MembershipDAOHibernate.addAllUsersToGroup(MembershipDAOHibernate.java:64)
	at com.atlassian.crowd.directory.CachingDirectory.addAllUsersToGroup(CachingDirectory.java:128)
	at com.atlassian.crowd.directory.DbCachingRemoteDirectoryCache.syncUserMembershipsForGroup(DbCachingRemoteDirectoryCache.java:697)
	at com.atlassian.crowd.directory.ldap.cache.UsnChangedCacheRefresher.synchroniseMembershipsForGroup(UsnChangedCacheRefresher.java:110)
	at com.atlassian.crowd.directory.ldap.cache.AbstractCacheRefresher.synchroniseMemberships(AbstractCacheRefresher.java:70)
	at com.atlassian.crowd.directory.ldap.cache.AbstractCacheRefresher.synchroniseAll(AbstractCacheRefresher.java:40)
	at com.atlassian.crowd.directory.ldap.cache.UsnChangedCacheRefresher.synchroniseAll(UsnChangedCacheRefresher.java:212)
	at com.atlassian.crowd.directory.DbCachingRemoteDirectory.synchroniseCache(DbCachingRemoteDirectory.java:645)
	at com.atlassian.crowd.manager.directory.DirectorySynchroniserHelperImpl.synchronise(DirectorySynchroniserHelperImpl.java:84)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
	at com.atlassian.spring.interceptors.SpringProfilingInterceptor.invoke(SpringProfilingInterceptor.java:20)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at $Proxy6.synchronise(Unknown Source)
	at com.atlassian.crowd.manager.directory.DirectorySynchroniserImpl.synchronise(DirectorySynchroniserImpl.java:59)
	at com.atlassian.crowd.directory.DbCachingDirectoryPoller.pollChanges(DbCachingDirectoryPoller.java:50)
	at com.atlassian.crowd.manager.directory.monitor.poller.DirectoryPollerJobBean.executeInternal(DirectoryPollerJobBean.java:29)
	at org.springframework.scheduling.quartz.QuartzJobBean.execute(QuartzJobBean.java:86)
	at org.quartz.core.JobRunShell.run(JobRunShell.java:195)
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:520)
Caused by: java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
	at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:2007)
	at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:1443)
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:1723)
	at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:48)
	at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:246)
	... 41 more
2011-04-29 16:32:53,072 scheduler_Worker-9 WARN [persistence.hibernate.batch.AbstractBatchProcessor] batch failed falling back to individual processing
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
	at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
	at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:253)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:237)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
	at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
	at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
	at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
	at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate3.Hibernate3BatchProcessor.flushSession(Hibernate3BatchProcessor.java:45)
	at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate3.Hibernate3BatchProcessor.commitTransaction(Hibernate3BatchProcessor.java:122)
	at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate3.Hibernate3BatchProcessor.afterProcessBatch(Hibernate3BatchProcessor.java:91)
	at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.processBatch(AbstractBatchProcessor.java:160)
	at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.execute(AbstractBatchProcessor.java:132)
	at com.atlassian.crowd.dao.membership.MembershipDAOHibernate.addAll(MembershipDAOHibernate.java:303)
	at com.atlassian.crowd.dao.membership.MembershipDAOHibernate.addAllUsersToGroup(MembershipDAOHibernate.java:64)
	at com.atlassian.crowd.directory.CachingDirectory.addAllUsersToGroup(CachingDirectory.java:128)
	at com.atlassian.crowd.directory.DbCachingRemoteDirectoryCache.syncUserMembershipsForGroup(DbCachingRemoteDirectoryCache.java:697)
	at com.atlassian.crowd.directory.ldap.cache.UsnChangedCacheRefresher.synchroniseMembershipsForGroup(UsnChangedCacheRefresher.java:110)
	at com.atlassian.crowd.directory.ldap.cache.AbstractCacheRefresher.synchroniseMemberships(AbstractCacheRefresher.java:70)
	at com.atlassian.crowd.directory.ldap.cache.AbstractCacheRefresher.synchroniseAll(AbstractCacheRefresher.java:40)
	at com.atlassian.crowd.directory.ldap.cache.UsnChangedCacheRefresher.synchroniseAll(UsnChangedCacheRefresher.java:212)
	at com.atlassian.crowd.directory.DbCachingRemoteDirectory.synchroniseCache(DbCachingRemoteDirectory.java:645)
	at com.atlassian.crowd.manager.directory.DirectorySynchroniserHelperImpl.synchronise(DirectorySynchroniserHelperImpl.java:84)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
	at com.atlassian.spring.interceptors.SpringProfilingInterceptor.invoke(SpringProfilingInterceptor.java:20)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at $Proxy6.synchronise(Unknown Source)
	at com.atlassian.crowd.manager.directory.DirectorySynchroniserImpl.synchronise(DirectorySynchroniserImpl.java:59)
	at com.atlassian.crowd.directory.DbCachingDirectoryPoller.pollChanges(DbCachingDirectoryPoller.java:50)
	at com.atlassian.crowd.manager.directory.monitor.poller.DirectoryPollerJobBean.executeInternal(DirectoryPollerJobBean.java:29)
	at org.springframework.scheduling.quartz.QuartzJobBean.execute(QuartzJobBean.java:86)
	at org.quartz.core.JobRunShell.run(JobRunShell.java:195)
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:520)
Caused by: java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
	at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:2007)
	at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:1443)
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:1723)
	at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:48)
	at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:246)
	... 41 more
2011-04-29 16:33:46,247 scheduler_Worker-9 WARN [org.hibernate.util.JDBCExceptionReporter] SQL Error: 1205, SQLState: 41000
2011-04-29 16:33:46,247 scheduler_Worker-9 ERROR [org.hibernate.util.JDBCExceptionReporter] Lock wait timeout exceeded; try restarting transaction
2011-04-29 16:33:46,247 scheduler_Worker-9 ERROR [hibernate.event.def.AbstractFlushingEventListener] Could not synchronize database state with session
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
	at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
	at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:253)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:237)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
	at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
	at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
	at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
	at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate3.Hibernate3BatchProcessor.flushSession(Hibernate3BatchProcessor.java:45)
	at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate3.Hibernate3BatchProcessor.commitTransaction(Hibernate3BatchProcessor.java:122)
	at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate3.Hibernate3BatchProcessor.afterProcessIndividual(Hibernate3BatchProcessor.java:106)
	at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.processIndividual(AbstractBatchProcessor.java:187)
	at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.processBatch(AbstractBatchProcessor.java:168)
	at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.execute(AbstractBatchProcessor.java:132)
	at com.atlassian.crowd.dao.membership.MembershipDAOHibernate.addAll(MembershipDAOHibernate.java:303)
	at com.atlassian.crowd.dao.membership.MembershipDAOHibernate.addAllUsersToGroup(MembershipDAOHibernate.java:64)
	at com.atlassian.crowd.directory.CachingDirectory.addAllUsersToGroup(CachingDirectory.java:128)
	at com.atlassian.crowd.directory.DbCachingRemoteDirectoryCache.syncUserMembershipsForGroup(DbCachingRemoteDirectoryCache.java:697)
	at com.atlassian.crowd.directory.ldap.cache.UsnChangedCacheRefresher.synchroniseMembershipsForGroup(UsnChangedCacheRefresher.java:110)
	at com.atlassian.crowd.directory.ldap.cache.AbstractCacheRefresher.synchroniseMemberships(AbstractCacheRefresher.java:70)
	at com.atlassian.crowd.directory.ldap.cache.AbstractCacheRefresher.synchroniseAll(AbstractCacheRefresher.java:40)
	at com.atlassian.crowd.directory.ldap.cache.UsnChangedCacheRefresher.synchroniseAll(UsnChangedCacheRefresher.java:212)
	at com.atlassian.crowd.directory.DbCachingRemoteDirectory.synchroniseCache(DbCachingRemoteDirectory.java:645)
	at com.atlassian.crowd.manager.directory.DirectorySynchroniserHelperImpl.synchronise(DirectorySynchroniserHelperImpl.java:84)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
	at com.atlassian.spring.interceptors.SpringProfilingInterceptor.invoke(SpringProfilingInterceptor.java:20)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at $Proxy6.synchronise(Unknown Source)
	at com.atlassian.crowd.manager.directory.DirectorySynchroniserImpl.synchronise(DirectorySynchroniserImpl.java:59)
	at com.atlassian.crowd.directory.DbCachingDirectoryPoller.pollChanges(DbCachingDirectoryPoller.java:50)
	at com.atlassian.crowd.manager.directory.monitor.poller.DirectoryPollerJobBean.executeInternal(DirectoryPollerJobBean.java:29)
	at org.springframework.scheduling.quartz.QuartzJobBean.execute(QuartzJobBean.java:86)
	at org.quartz.core.JobRunShell.run(JobRunShell.java:195)
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:520)
Caused by: java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
	at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:2007)
	at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:1443)
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:1723)
	at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:48)
	at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:246)
	... 42 more
2011-04-29 16:33:46,296 scheduler_Worker-9 ERROR [persistence.hibernate.batch.AbstractBatchProcessor] Could not process class com.atlassian.crowd.model.membership.InternalMembership: com.atlassian.crowd.model.membership.InternalMembership@49b3a360[parentId=917506,childId=884740,membershipType=GROUP_USER,groupType=GROUP,parentName=testgroup,lowerParentName=testgroup,childName=SpaceUser,lowerChildName=spaceuser,directoryId=851969]
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
	at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
	at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:253)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:237)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
	at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
	at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
	at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
	at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate3.Hibernate3BatchProcessor.flushSession(Hibernate3BatchProcessor.java:45)
	at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate3.Hibernate3BatchProcessor.commitTransaction(Hibernate3BatchProcessor.java:122)
	at com.atlassian.crowd.util.persistence.hibernate.batch.hibernate3.Hibernate3BatchProcessor.afterProcessIndividual(Hibernate3BatchProcessor.java:106)
	at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.processIndividual(AbstractBatchProcessor.java:187)
	at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.processBatch(AbstractBatchProcessor.java:168)
	at com.atlassian.crowd.util.persistence.hibernate.batch.AbstractBatchProcessor.execute(AbstractBatchProcessor.java:132)
	at com.atlassian.crowd.dao.membership.MembershipDAOHibernate.addAll(MembershipDAOHibernate.java:303)
	at com.atlassian.crowd.dao.membership.MembershipDAOHibernate.addAllUsersToGroup(MembershipDAOHibernate.java:64)
	at com.atlassian.crowd.directory.CachingDirectory.addAllUsersToGroup(CachingDirectory.java:128)
	at com.atlassian.crowd.directory.DbCachingRemoteDirectoryCache.syncUserMembershipsForGroup(DbCachingRemoteDirectoryCache.java:697)
	at com.atlassian.crowd.directory.ldap.cache.UsnChangedCacheRefresher.synchroniseMembershipsForGroup(UsnChangedCacheRefresher.java:110)
	at com.atlassian.crowd.directory.ldap.cache.AbstractCacheRefresher.synchroniseMemberships(AbstractCacheRefresher.java:70)
	at com.atlassian.crowd.directory.ldap.cache.AbstractCacheRefresher.synchroniseAll(AbstractCacheRefresher.java:40)
	at com.atlassian.crowd.directory.ldap.cache.UsnChangedCacheRefresher.synchroniseAll(UsnChangedCacheRefresher.java:212)
	at com.atlassian.crowd.directory.DbCachingRemoteDirectory.synchroniseCache(DbCachingRemoteDirectory.java:645)
	at com.atlassian.crowd.manager.directory.DirectorySynchroniserHelperImpl.synchronise(DirectorySynchroniserHelperImpl.java:84)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
	at com.atlassian.spring.interceptors.SpringProfilingInterceptor.invoke(SpringProfilingInterceptor.java:20)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.orm.hibernate3.HibernateInterceptor.invoke(HibernateInterceptor.java:111)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at $Proxy6.synchronise(Unknown Source)
	at com.atlassian.crowd.manager.directory.DirectorySynchroniserImpl.synchronise(DirectorySynchroniserImpl.java:59)
	at com.atlassian.crowd.directory.DbCachingDirectoryPoller.pollChanges(DbCachingDirectoryPoller.java:50)
	at com.atlassian.crowd.manager.directory.monitor.poller.DirectoryPollerJobBean.executeInternal(DirectoryPollerJobBean.java:29)
	at org.springframework.scheduling.quartz.QuartzJobBean.execute(QuartzJobBean.java:86)
	at org.quartz.core.JobRunShell.run(JobRunShell.java:195)
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:520)
Caused by: java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
	at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:2007)
	at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:1443)
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:1723)
	at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:48)
	at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:246)
	... 42 more
2011-04-29 16:33:46,297 scheduler_Worker-9 INFO [persistence.hibernate.batch.AbstractBatchProcessor] processed batch [ 1 ] of [ 1 ] [ 100.0 % ]
2011-04-29 16:33:46,297 scheduler_Worker-9 WARN [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] Could not add the following missing users to group [ testgroup ]: [SpaceUser]
2011-04-29 16:33:46,297 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectoryCache] added [ 0 ] user members to [ testgroup ] in [ 104967ms ]
2011-04-29 16:33:46,300 scheduler_Worker-9 INFO [directory.ldap.cache.AbstractCacheRefresher] Migrated memberships for [0] of [3] groups
2011-04-29 16:33:46,300 scheduler_Worker-9 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 0 ] remote user-group memberships in [ 0ms ]
2011-04-29 16:33:46,300 scheduler_Worker-9 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 0 ] remote group-group memberships in [ 0ms ]
2011-04-29 16:33:46,305 scheduler_Worker-9 INFO [directory.ldap.cache.AbstractCacheRefresher] Migrated memberships for [1] of [3] groups
2011-04-29 16:33:46,305 scheduler_Worker-9 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 1 ] remote user-group memberships in [ 0ms ]
2011-04-29 16:33:46,305 scheduler_Worker-9 INFO [directory.ldap.cache.UsnChangedCacheRefresher] found [ 0 ] remote group-group memberships in [ 0ms ]
2011-04-29 16:33:46,311 scheduler_Worker-9 INFO [directory.ldap.cache.AbstractCacheRefresher] Migrated memberships for [2] of [3] groups
2011-04-29 16:33:46,312 scheduler_Worker-9 INFO [atlassian.crowd.directory.DbCachingRemoteDirectory] synchronisation complete in [ 107193ms ]

is caused by

CWD-2437 Combined operations in DirectoryCache should be split in parts

Closed

is related to

CWD-2441 Use sAMAccountName attribute for group name by default when using Active Directory

Closed

Monique Khairuliana (Inactive) made changes - 15/Aug/2019 7:05 AM

Workflow	Original: Simplified Crowd Development Workflow v2 - restricted [ 1509639 ]	New: JAC Bug Workflow v3 [ 3364675 ]
Status	Original: Resolved [ 5 ]	New: Closed [ 6 ]

Owen made changes - 07/Jul/2016 6:18 AM

Workflow

Original: Simplified Crowd Development Workflow v2 [ 1391819 ]

New: Simplified Crowd Development Workflow v2 - restricted [ 1509639 ]

Owen made changes - 12/May/2016 2:51 AM

Workflow

Original: Crowd Development Workflow v2 [ 291760 ]

New: Simplified Crowd Development Workflow v2 [ 1391819 ]

Olli Nevalainen made changes - 19/Jul/2011 4:21 AM

Link

New: This issue is caused by ~~CWD-2437~~ [ ~~CWD-2437~~ ]

Olli Nevalainen made changes - 19/Jul/2011 4:18 AM

Link

Original: This issue is caused by ~~CWD-2430~~ [ ~~CWD-2430~~ ]

joe made changes - 11/May/2011 2:33 AM

Resolution		New: Fixed [ 1 ]
Status	Original: Open [ 1 ]	New: Resolved [ 5 ]

joe made changes - 11/May/2011 2:33 AM

Link

New: This issue is related to ~~CWD-2441~~ [ ~~CWD-2441~~ ]

shihab made changes - 05/May/2011 6:13 AM

Fix Version/s

New: 2.2.7 [ 17004 ]

Olli Nevalainen added a comment - 05/May/2011 6:05 AM

There are two ways to get around this issue in current installations:

The obvious quick fix for this issue is to ensure that CN attribute is unique by giving duplicate groups another name.

Another (untested) way is to change Group Name Attribute to sAMAccountName and remove "Add Group" permission from the directory. Without ~~CWD-2441~~ bad things would happen if a group was added in AD through the Crowd UI. Also group names might change completely with this change as sAMAccountName attribute does not have to have the same value as CN attribute.

Olli Nevalainen added a comment - 05/May/2011 6:05 AM There are two ways to get around this issue in current installations: The obvious quick fix for this issue is to ensure that CN attribute is unique by giving duplicate groups another name. Another (untested) way is to change Group Name Attribute to sAMAccountName and remove "Add Group" permission from the directory. Without CWD-2441 bad things would happen if a group was added in AD through the Crowd UI. Also group names might change completely with this change as sAMAccountName attribute does not have to have the same value as CN attribute.

Olli Nevalainen added a comment - 05/May/2011 5:43 AM

Crowd synchronisation algorithm expects the group names to be unique, but CN is not quaranteed to be unique. ~~CWD-2430~~ will fix the synchronisation, but only one group will be synchronised when encountering duplicate group names. ~~CWD-2441~~ has been created to track handling groups with duplicate CN by using sAMAccountName attribute instead.

Given that there are two groups (=A and B) with the same CN (=testGroup) a deadlock can happen in the following way:

Directory is synchronised (Transaction T1)
1. A is synchronised against testGroup
  1. A's memberships are added to testGroup (Transaction T2)
2. B is synchronised against testGroup
  1. B's memberships are added to testGroup (Transaction T3)
  2. A's memberships are deleted from testGroup
Directory is synchronised again (Transaction T4)
1. A is synchronised against testGroup
  1. A's memberships are added to testGroup (Transaction T5)
  2. B's memberships are deleted from testGroup
2. B is synchronised against testGroup
  1. B's memberships are added to testGroup (Transaction T6) (HANG!)

In 2.1.2. B's memberships are deleted in transaction T4 and then added again in 2.2.1 in transaction T6. T6 cannot insert the memberships before T4 has either committed or rolled back deleting the same memberships. T4 cannot continue before T6 has committed or rolled back because T6 is executed inside T4.

Olli Nevalainen added a comment - 05/May/2011 5:43 AM Crowd synchronisation algorithm expects the group names to be unique, but CN is not quaranteed to be unique. CWD-2430 will fix the synchronisation, but only one group will be synchronised when encountering duplicate group names. CWD-2441 has been created to track handling groups with duplicate CN by using sAMAccountName attribute instead. Given that there are two groups (=A and B) with the same CN (=testGroup) a deadlock can happen in the following way: Directory is synchronised (Transaction T1) A is synchronised against testGroup A's memberships are added to testGroup (Transaction T2) B is synchronised against testGroup B's memberships are added to testGroup (Transaction T3) A's memberships are deleted from testGroup Directory is synchronised again (Transaction T4) A is synchronised against testGroup A's memberships are added to testGroup (Transaction T5) B's memberships are deleted from testGroup B is synchronised against testGroup B's memberships are added to testGroup (Transaction T6) (HANG!) In 2.1.2. B's memberships are deleted in transaction T4 and then added again in 2.2.1 in transaction T6. T6 cannot insert the memberships before T4 has either committed or rolled back deleting the same memberships. T4 cannot continue before T6 has committed or rolled back because T6 is executed inside T4.

Assignee:: Russell Martin [Atlassian]

Reporter:: Robert Chang

Affected customers:: 1 This affects my team

Watchers:: 2 Start watching this issue

Created:: 30/Apr/2011 12:46 AM

Updated:: 15/Aug/2019 7:05 AM

Resolved:: 11/May/2011 2:33 AM

Details

Description

Attachments

Issue Links

Forms

Activity

Collapse comment: Olli Nevalainen added a comment - 05/May/2011 6:05 AM

Expand comment: Olli Nevalainen added a comment - 05/May/2011 6:05 AM

Collapse comment: Olli Nevalainen added a comment - 05/May/2011 5:43 AM

Expand comment: Olli Nevalainen added a comment - 05/May/2011 5:43 AM

People

Dates