Concurrent calls to store user attributes may cause SQL exception

Summary of Issue

When Jira, Confluence, Bitbucket or Bamboo is integrated with Crowd SSO, Crowd can throw deadlock errors in the atlassian-crowd.log. The user login session associated with the database deadlock is likely to be rejected.

Environment

• Crowd is on MySQL or Oracle (others may be affected but not verified)

How to reproduce

1. Install Confluence 6.15.4 with Crowd Seraph SSO enabled
2. In Crowd, create two users in the internal Crowd User Directory and grant them confluence-users
3. Confirm that you can log into Confluence with the two users above (this should authenticate into Crowd via SSO)
4. Now, simulate high load on an authenticated Confluence page using curl:

   curl -s -u <user>:<password> http://localhost:8090/display/DS
   curl -s -u <user>:<password> http://localhost:8090/browsepeople.action
   

   • Randomly alternate between user1:password1 and user2:password2
   • In the testing, 100 simultaneous requests were sent to Confluence to simulate high load and higher chance to force the deadlock and the deadlock could always be reproduced within 5 minutes

Expected result

There should be no errors in the Crowd log, specifically, deadlock errors in relation to cwd_user_attribute table.

Actual result

1. Tail the atlassian-crowd.log and it will eventually throw a deadlock error on cwd_user_attribute:

   2019-05-14 14:29:30,300 http-nio-6343-exec-30 ERROR [jdbc.batch.internal.BatchingBatch] HHH000315: Exception executing batch [java.sql.BatchUpdateException: Deadlock found when trying to get lock; try restarting transaction], SQL: update cwd_user_attribute set user_id=?, directory_id=?, attribute_name=?, attribute_value=?, attribute_lower_value=?, attribute_numeric_value=? where id=?
   2019-05-14 14:29:30,300 http-nio-6343-exec-30 WARN [engine.jdbc.spi.SqlExceptionHelper] SQL Error: 1213, SQLState: 40001
   

2. With this stack trace:

   2019-05-14 14:29:30,300 http-nio-6343-exec-30 ERROR [engine.jdbc.spi.SqlExceptionHelper] Deadlock found when trying to get lock; try restarting transaction
   2019-05-14 14:29:30,307 http-nio-6343-exec-30 ERROR [springframework.transaction.interceptor.TransactionInterceptor] Application exception overridden by commit exception
   com.atlassian.crowd.exception.OperationFailedException: javax.persistence.PersistenceException: org.hibernate.exception.LockAcquisitionException: could not execute batch
   	at com.atlassian.crowd.directory.AbstractInternalDirectory.storeUserAttributes(AbstractInternalDirectory.java:654)
   	at com.atlassian.crowd.directory.AbstractInternalDirectory.userAuthenticated(AbstractInternalDirectory.java:215)
   	at com.atlassian.crowd.manager.directory.DirectoryManagerGeneric.userAuthenticated(DirectoryManagerGeneric.java:288)
   ...
   	at com.atlassian.crowd.manager.application.ApplicationServiceGeneric.userAuthenticated(ApplicationServiceGeneric.java:2370)
   ...
   	at com.sun.proxy.$Proxy76.userAuthenticated(Unknown Source)
   	at com.atlassian.crowd.manager.application.AbstractDelegatingApplicationService.userAuthenticated(AbstractDelegatingApplicationService.java:358)
   ...
   	at com.atlassian.crowd.manager.application.TranslatingApplicationService.userAuthenticated(TranslatingApplicationService.java:335)
   ...
   	at com.atlassian.crowd.plugin.rest.filter.BasicApplicationAuthenticationFilter.executeOnBehalfOfApplication(BasicApplicationAuthenticationFilter.java:134)
   	at com.atlassian.crowd.plugin.rest.filter.BasicApplicationAuthenticationFilter.doFilter(BasicApplicationAuthenticationFilter.java:105)
   	at com.atlassian.plugin.servlet.filter.DelegatingPluginFilter.doFilter(DelegatingPluginFilter.java:64)
   	at com.atlassian.plugin.servlet.filter.IteratingFilterChain.doFilter(IteratingFilterChain.java:37)
   	at com.atlassian.plugin.servlet.filter.ServletFilterModuleContainerFilter.doFilter(ServletFilterModuleContainerFilter.java:70)
   	at com.atlassian.plugin.servlet.filter.ServletFilterModuleContainerFilter.doFilter(ServletFilterModuleContainerFilter.java:58)
   ...
   	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650)
   	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
   	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:800)
   	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
   	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806)
   	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498)
   	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
   	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:748)
   Caused by: javax.persistence.PersistenceException: org.hibernate.exception.LockAcquisitionException: could not execute batch
   	at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:147)
   	at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:155)
   	at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:162)
   	at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1441)
   	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1421)
   	at com.atlassian.crowd.util.persistence.hibernate.InternalDirectoryEntityHibernateDao.storeAttributes(InternalDirectoryEntityHibernateDao.java:117)
   	at com.atlassian.crowd.dao.user.UserDAOHibernate.storeAttributes(UserDAOHibernate.java:468)
   	at com.atlassian.crowd.directory.AbstractInternalDirectory.storeUserAttributes(AbstractInternalDirectory.java:652)
   	... 329 more
   Caused by: org.hibernate.exception.LockAcquisitionException: could not execute batch
   	at org.hibernate.dialect.MySQLDialect$3.convert(MySQLDialect.java:536)
   	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
   	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111)
   	at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:121)
   	at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:97)
   	at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.execute(AbstractBatchImpl.java:147)
   	at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.executeBatch(JdbcCoordinatorImpl.java:206)
   	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:618)
   	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:463)
   	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337)
   	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
   	at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1435)
   	... 333 more
   Caused by: java.sql.BatchUpdateException: Deadlock found when trying to get lock; try restarting transaction
   	at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1799)
   	at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:1271)
   	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:1135)
   	at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:111)
   	... 341 more
   Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
   	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
   	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
   	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
   	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
   	at com.mysql.jdbc.Util.handleNewInstance(Util.java:400)
   	at com.mysql.jdbc.Util.getInstance(Util.java:383)
   	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
   	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3847)
   	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3783)
   	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2447)
   	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2594)
   	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2545)
   	at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1901)
   	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2113)
   	at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1767)
   	... 344 more