Uploaded image for project: 'Crowd Data Center'
  1. Crowd Data Center
  2. CWD-4330

Concurrent calls to store user attributes may cause SQL exception

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Highest Highest
    • None
    • 2.8.2, 3.4.3
    • Database, Performance

      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
        

            [CWD-4330] Concurrent calls to store user attributes may cause SQL exception

            SET Analytics Bot made changes -
            Support reference count Original: 31 New: 32
            SET Analytics Bot made changes -
            UIS Original: 11 New: 10
            SET Analytics Bot made changes -
            UIS Original: 10 New: 11
            SET Analytics Bot made changes -
            UIS Original: 11 New: 10
            Jakub Mrozowski made changes -
            Remote Link Original: This issue links to "LEM-330 (SDOG)" [ 101556 ] New: This issue links to "POR-330 (SDOG)" [ 101556 ]
            SET Analytics Bot made changes -
            Support reference count Original: 30 New: 31
            SET Analytics Bot made changes -
            UIS Original: 10 New: 11
            SET Analytics Bot made changes -
            UIS Original: 11 New: 10
            SET Analytics Bot made changes -
            UIS Original: 10 New: 11
            SET Analytics Bot made changes -
            UIS Original: 9 New: 10

              Unassigned Unassigned
              dberrueta Diego Berrueta
              Affected customers:
              6 This affects my team
              Watchers:
              22 Start watching this issue

                Created:
                Updated: