Uploaded image for project: 'Bitbucket Server'
  1. Bitbucket Server
  2. BSERV-4517

Empty activity deletion deadlocks on MySQL

    XMLWordPrintable

    Details

      Description

      Symptoms

      This issue might cause Pull Requests to misbehave as well as a number of performance issues on your instance. As an example of PRs misbehaviour, it's been reported:

      (...) the following error more and more frequently when trying to merge a PR from the Stash UI (happening on multiple repos): "New changes were pushed to master in project/repo while the merge was being performed. Please retry the merge.

      You will find similar stack traces in your logs:

      atlassian.log
      2014-01-24 01:48:07,044 WARN  [rescope-details:thread-2] nj9312 108x272810x0 j74y32 10.1.52.24 SSH - git-receive-pack '/consumer/yp.git' c.a.s.i.p.r.DefaultRescopeProcessor 345: Could not delete empty rescope with ID 1471
      org.hibernate.exception.LockAcquisitionException: could not execute statement
      	at org.hibernate.dialect.MySQLDialect$1.convert(MySQLDialect.java:411) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
      	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
      	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
      	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
      	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:136) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
      	at org.hibernate.hql.spi.TableBasedDeleteHandlerImpl.execute(TableBasedDeleteHandlerImpl.java:163) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
      	at org.hibernate.hql.internal.ast.exec.MultiTableDeleteExecutor.execute(MultiTableDeleteExecutor.java:63) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
      	at org.hibernate.hql.internal.ast.QueryTranslatorImpl.executeUpdate(QueryTranslatorImpl.java:414) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
      	at org.hibernate.engine.query.spi.HQLQueryPlan.performExecuteUpdate(HQLQueryPlan.java:282) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
      	at org.hibernate.internal.SessionImpl.executeUpdate(SessionImpl.java:1290) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
      	at org.hibernate.internal.QueryImpl.executeUpdate(QueryImpl.java:116) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
      	at com.atlassian.stash.internal.AbstractHibernateDao.deleteById(AbstractHibernateDao.java:53) ~[stash-dao-impl-2.9.2.jar:na]
      	at com.atlassian.stash.internal.AbstractHibernateDao.deleteById(AbstractHibernateDao.java:22) ~[stash-dao-impl-2.9.2.jar:na]
      	at com.sun.proxy.$Proxy156.deleteById(Unknown Source) ~[na:na]
      	at com.atlassian.stash.internal.pull.rescope.DefaultRescopeProcessor$3.doInTransactionWithoutResult(DefaultRescopeProcessor.java:139) ~[stash-service-impl-2.9.2.jar:na]
      	at org.springframework.transaction.support.TransactionCallbackWithoutResult.doInTransaction(TransactionCallbackWithoutResult.java:33) ~[spring-tx-3.2.4.RELEASE.jar:3.2.4.RELEASE]
      	at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:131) ~[spring-tx-3.2.4.RELEASE.jar:3.2.4.RELEASE]
      	at com.atlassian.stash.internal.pull.rescope.DefaultRescopeProcessor.deleteActivity(DefaultRescopeProcessor.java:130) [stash-service-impl-2.9.2.jar:na]
      	at com.atlassian.stash.internal.pull.rescope.DefaultRescopeProcessor.processAll(DefaultRescopeProcessor.java:100) [stash-service-impl-2.9.2.jar:na]
      	at com.atlassian.stash.internal.pull.rescope.DefaultRescopeProcessor.process(DefaultRescopeProcessor.java:77) [stash-service-impl-2.9.2.jar:na]
      	at com.atlassian.stash.internal.pull.rescope.DefaultRescopeProcessor$RescopeCalculator.run(DefaultRescopeProcessor.java:219) ~[stash-service-impl-2.9.2.jar:na]
      	at com.atlassian.stash.internal.concurrent.StateTransferringExecutor$StateTransferringRunnable.run(StateTransferringExecutor.java:69) ~[stash-platform-2.9.2.jar:na]
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) ~[na:1.7.0_25]
      	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) ~[na:1.7.0_25]
      	at java.util.concurrent.FutureTask.run(FutureTask.java:166) ~[na:1.7.0_25]
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_25]
      	at java.lang.Thread.run(Thread.java:724) ~[na:1.7.0_25]
      	... 10 frames trimmed
      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) ~[na:1.7.0_25]
      	at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) ~[mysql-connector-java-5.1.22-bin.jar:na]
      	at com.mysql.jdbc.Util.getInstance(Util.java:386) ~[mysql-connector-java-5.1.22-bin.jar:na]
      	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1065) ~[mysql-connector-java-5.1.22-bin.jar:na]
      	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4096) ~[mysql-connector-java-5.1.22-bin.jar:na]
      	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4028) ~[mysql-connector-java-5.1.22-bin.jar:na]
      	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2490) ~[mysql-connector-java-5.1.22-bin.jar:na]
      	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2651) ~[mysql-connector-java-5.1.22-bin.jar:na]
      	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2734) ~[mysql-connector-java-5.1.22-bin.jar:na]
      	at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2155) ~[mysql-connector-java-5.1.22-bin.jar:na]
      	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2458) ~[mysql-connector-java-5.1.22-bin.jar:na]
      	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2375) ~[mysql-connector-java-5.1.22-bin.jar:na]
      	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2359) ~[mysql-connector-java-5.1.22-bin.jar:na]
      	at com.jolbox.bonecp.PreparedStatementHandle.executeUpdate(PreparedStatementHandle.java:203) ~[bonecp-0.7.1.RELEASE.jar:0.7.1.RELEASE]
      	at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:133) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
      	... 23 common frames omitted
      

      Cause

      This issue affects all versions of Stash from 2.5.0 through the just released 2.12.0. It is 100% MySQL-specific, and should not affect customers using any other database.

      Solution

      Upgrade to the indicated fix releases.

      Workaround

      Exactly because of this issue and STASH-4701, we recommend that customers with larger instances (you can consider that 500+ licenses) move off MySQL (you can see the warning we placed on Connecting Stash to MySQL). Therefore, if you can move to an alternative database (for example, PostgreSQL) in case you don't want to upgrade now, that'd also solve this issue for you.

      Leaving as-is will cause you performance issues as well as Pull Requests misbehaviour while merging. For instance:

      (...)the following error more and more frequently when trying to merge a PR from the Stash UI (happening on multiple repos): "New changes were pushed to master in project/repo while the merge was being performed. Please retry the merge."

      The good news is that Stash makes it really easy for you to migrate databases. All you have to do is:

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              bturner Bryan Turner
              Reporter:
              cofarrell Charles O'Farrell [Atlassian]
              Votes:
              0 Vote for this issue
              Watchers:
              10 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: