Uploaded image for project: 'Jira Software Data Center'
  1. Jira Software Data Center
  2. JSWSERVER-14560

Project Import heavily delayed when LexoRank re-balance is running

    XMLWordPrintable

Details

    • Bug
    • Resolution: Unresolved
    • Low
    • None
    • 7.3.0
    • None

    Description

      Summary

      When importing a project into JIRA, it will generate rank values for each issue imported. While a Rank field is being re-balance, ranking of new issues will be heavily delayed.

      Expected Behavior

      Re-balancing should introduce minimal overhead in JIRA's operations, including initially ranking imported or new issues and also performing other ranking operations.

      Actual Behavior

      At the time of generating rank values for the newly-imported issues (see log entries below), there is a big difference in the time for each rank value to be generated.

      2016-06-24 15:14:10,201 JiraTaskExectionThread-3 INFO admin 900x1326x1 2mgjls 127.0.0.1 /secure/admin/ProjectImportSummary.jspa [c.a.j.i.p.ao.handler.PluggableImportAoEntityHandler] No rank data exists for fields [13441], default ranks will be used
      2016-06-24 15:28:27,454 JiraTaskExectionThread-3 INFO admin 900x1326x1 2mgjls 127.0.0.1 /secure/admin/ProjectImportSummary.jspa [c.a.j.i.p.ao.handler.PluggableImportAoEntityHandler] Generated 1000 out of 58178 ranks (0 errors)
      2016-06-24 15:42:38,066 JiraTaskExectionThread-3 INFO admin 900x1326x1 2mgjls 127.0.0.1 /secure/admin/ProjectImportSummary.jspa [c.a.j.i.p.ao.handler.PluggableImportAoEntityHandler] Generated 2000 out of 58178 ranks (0 errors)
      2016-06-24 15:57:29,303 JiraTaskExectionThread-3 INFO admin 900x1326x1 2mgjls 127.0.0.1 /secure/admin/ProjectImportSummary.jspa [c.a.j.i.p.ao.handler.PluggableImportAoEntityHandler] Generated 3000 out of 58178 ranks (0 errors)
      2016-06-24 16:11:59,238 JiraTaskExectionThread-3 INFO admin 900x1326x1 2mgjls 127.0.0.1 /secure/admin/ProjectImportSummary.jspa [c.a.j.i.p.ao.handler.PluggableImportAoEntityHandler] Generated 4000 out of 58178 ranks (0 errors)
      2016-06-24 16:26:17,889 JiraTaskExectionThread-3 INFO admin 900x1326x1 2mgjls 127.0.0.1 /secure/admin/ProjectImportSummary.jspa [c.a.j.i.p.ao.handler.PluggableImportAoEntityHandler] Generated 5000 out of 58178 ranks (0 errors)
      2016-06-24 16:40:51,441 JiraTaskExectionThread-3 INFO admin 900x1326x1 2mgjls 127.0.0.1 /secure/admin/ProjectImportSummary.jspa [c.a.j.i.p.ao.handler.PluggableImportAoEntityHandler] Generated 6000 out of 58178 ranks (0 errors)
      ...
      

      During our tests, while re-balance was running, each 1000 issues took about 6 minutes to have rank values assigned. Whereas, while re-balance was not running, the same amount of issues had rank values generated in 6 to 10 seconds.

      The below stack trace shows the methods involved in generating rank values on a project import.

      "JiraTaskExectionThread-17" daemon prio=5 tid=0x0000000000031c58 nid=0 runnable 
         java.lang.Thread.State: RUNNABLE
      	at java.net.SocketInputStream.socketRead0(Native Method)
      	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
      	at java.net.SocketInputStream.read(SocketInputStream.java:170)
      	at java.net.SocketInputStream.read(SocketInputStream.java:141)
      	at java.io.DataInputStream.readFully(DataInputStream.java:195)
      	at java.io.DataInputStream.readFully(DataInputStream.java:169)
      	at net.sourceforge.jtds.jdbc.SharedSocket.readPacket(SharedSocket.java:850)
      	at net.sourceforge.jtds.jdbc.SharedSocket.getNetPacket(SharedSocket.java:731)
      	- locked <0x0000000041249b5f> (a java.util.concurrent.ConcurrentHashMap)
      	at net.sourceforge.jtds.jdbc.ResponseStream.getPacket(ResponseStream.java:477)
      	at net.sourceforge.jtds.jdbc.ResponseStream.read(ResponseStream.java:114)
      	at net.sourceforge.jtds.jdbc.ResponseStream.peek(ResponseStream.java:99)
      	at net.sourceforge.jtds.jdbc.TdsCore.wait(TdsCore.java:4127)
      	at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1086)
      	- locked <0x0000000054654d16> (a net.sourceforge.jtds.jdbc.TdsCore)
      	at net.sourceforge.jtds.jdbc.JtdsStatement.executeSQL(JtdsStatement.java:563)
      	at net.sourceforge.jtds.jdbc.JtdsPreparedStatement.executeUpdate(JtdsPreparedStatement.java:727)
      	- locked <0x000000007ca7f26c> (a net.sourceforge.jtds.jdbc.JtdsConnection)
      	at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
      	at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
      	at com.atlassian.greenhopper.manager.lexorank.SqlUpdateStatement.execute(SqlUpdateStatement.java:51)
      	at com.atlassian.greenhopper.manager.lexorank.LexoRankDaoImpl.releaseLock(LexoRankDaoImpl.java:703)
      	at com.atlassian.greenhopper.service.lexorank.LexoRankOperation.rankInitially(LexoRankOperation.java:242)
      	- locked <0x0000000028d01916> (a java.lang.Object)
      	at com.atlassian.greenhopper.service.lexorank.LexoRankOperation.execute(LexoRankOperation.java:110)
      	at com.atlassian.greenhopper.manager.lexorank.LexoRankManagerImpl.performRankOperation(LexoRankManagerImpl.java:286)
      	at com.atlassian.greenhopper.manager.lexorank.LexoRankManagerImpl.getRankOrRankInitially(LexoRankManagerImpl.java:86)
      	at com.atlassian.greenhopper.imports.ProjectImportServiceImpl.rankAfter(ProjectImportServiceImpl.java:85)
      	at com.atlassian.greenhopper.imports.LexorankImportHandler.endTable(LexorankImportHandler.java:94)
      	at com.atlassian.jira.imports.project.ao.handler.ChainedAoSaxHandler.endTable(ChainedAoSaxHandler.java:260)
      	at com.atlassian.jira.imports.project.ao.handler.ChainedAoSaxHandler.endElement(ChainedAoSaxHandler.java:187)
      	at com.atlassian.jira.imports.project.ao.handler.ChainedAoSaxHandler.endElement(ChainedAoSaxHandler.java:148)
      	at org.apache.xerces.parsers.AbstractSAXParser.endElement(Unknown Source)
      	at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanEndElement(Unknown Source)
      	at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispatcher.dispatch(Unknown Source)
      	at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source)
      	at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
      	at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
      	at org.apache.xerces.parsers.XMLParser.parse(Unknown Source)
      	at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source)
      	at org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser.parse(Unknown Source)
      	at com.atlassian.security.xml.RestrictedXMLReader.parse(RestrictedXMLReader.java:103)
      	at com.atlassian.jira.imports.xml.DefaultBackupXmlParser$XmlParser.parseXml(DefaultBackupXmlParser.java:115)
      	at com.atlassian.jira.imports.xml.DefaultBackupXmlParser.parse(DefaultBackupXmlParser.java:64)
      	at com.atlassian.jira.imports.xml.DefaultBackupXmlParser.parseXml(DefaultBackupXmlParser.java:52)
      	at com.atlassian.jira.imports.xml.DefaultBackupXmlParser.parseAoBackupXml(DefaultBackupXmlParser.java:46)
      	at com.atlassian.jira.imports.project.DefaultProjectImportManager.importAoData(DefaultProjectImportManager.java:708)
      	at com.atlassian.jira.imports.project.DefaultProjectImportManager.doImport(DefaultProjectImportManager.java:656)
      	at com.atlassian.jira.bc.imports.project.DefaultProjectImportService.doImport(DefaultProjectImportService.java:416)
      	at com.atlassian.jira.web.action.admin.importer.project.ProjectImportSummary$ProjectImportCallable.call(ProjectImportSummary.java:285)
      	at com.atlassian.jira.web.action.admin.importer.project.ProjectImportSummary$ProjectImportCallable.call(ProjectImportSummary.java:236)
      	at com.atlassian.jira.task.TaskManagerImpl$TaskCallableDecorator.call(TaskManagerImpl.java:458)
      	at com.atlassian.jira.task.TaskManagerImpl$TaskCallableDecorator.call(TaskManagerImpl.java:426)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	at com.atlassian.jira.task.ForkedThreadExecutor$ForkedRunnableDecorator.run(ForkedThreadExecutor.java:216)
      	at java.lang.Thread.run(Thread.java:745)
      

      And the below two stack traces show methods involved on the re-balancing of a Rank field.

      "lexorank-executor-thread-0" prio=5 tid=0x0000000000000076 nid=0 runnable 
         java.lang.Thread.State: RUNNABLE
      	at java.net.SocketInputStream.socketRead0(Native Method)
      	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
      	at java.net.SocketInputStream.read(SocketInputStream.java:170)
      	at java.net.SocketInputStream.read(SocketInputStream.java:141)
      	at java.io.DataInputStream.readFully(DataInputStream.java:195)
      	at java.io.DataInputStream.readFully(DataInputStream.java:169)
      	at net.sourceforge.jtds.jdbc.SharedSocket.readPacket(SharedSocket.java:850)
      	at net.sourceforge.jtds.jdbc.SharedSocket.getNetPacket(SharedSocket.java:731)
      	- locked <0x0000000029a73764> (a java.util.concurrent.ConcurrentHashMap)
      	at net.sourceforge.jtds.jdbc.ResponseStream.getPacket(ResponseStream.java:477)
      	at net.sourceforge.jtds.jdbc.ResponseStream.read(ResponseStream.java:114)
      	at net.sourceforge.jtds.jdbc.ResponseStream.peek(ResponseStream.java:99)
      	at net.sourceforge.jtds.jdbc.TdsCore.wait(TdsCore.java:4127)
      	at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1086)
      	- locked <0x0000000055c07575> (a net.sourceforge.jtds.jdbc.TdsCore)
      	at net.sourceforge.jtds.jdbc.JtdsStatement.executeSQLQuery(JtdsStatement.java:493)
      	at net.sourceforge.jtds.jdbc.JtdsPreparedStatement.executeQuery(JtdsPreparedStatement.java:1029)
      	- locked <0x00000000633c42cd> (a net.sourceforge.jtds.jdbc.JtdsConnection)
      	at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
      	at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
      	at com.atlassian.greenhopper.manager.lexorank.SqlSelectStatement.execute(SqlSelectStatement.java:95)
      	at com.atlassian.greenhopper.manager.lexorank.LexoRankDaoImpl.find(LexoRankDaoImpl.java:1323)
      	at com.atlassian.greenhopper.manager.lexorank.LexoRankDaoImpl.getRowsAtBalanceBoundaryForFieldId(LexoRankDaoImpl.java:1049)
      	at com.atlassian.greenhopper.service.lexorank.balance.LexoRankBalanceOperation.moveNextRowToNextBucket(LexoRankBalanceOperation.java:190)
      	at com.atlassian.greenhopper.service.lexorank.balance.LexoRankBalanceOperation.execute(LexoRankBalanceOperation.java:105)
      	at com.atlassian.greenhopper.service.lexorank.balance.LexoRankBalancer.balanceFieldId(LexoRankBalancer.java:326)
      	at com.atlassian.greenhopper.service.lexorank.balance.LexoRankBalancer.balanceFieldIds(LexoRankBalancer.java:104)
      	at com.atlassian.greenhopper.service.lexorank.balance.LexoRankScheduledBalanceHandler.run(LexoRankScheduledBalanceHandler.java:60)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      	at java.lang.Thread.run(Thread.java:745)
      
      "LexoRankReindexer:thread-1" prio=5 tid=0x0000000000031d07 nid=0 waiting on condition 
         java.lang.Thread.State: TIMED_WAITING (parking)
      	at sun.misc.Unsafe.park(Native Method)
      	- parking to wait for <0x00000000205e9fb9> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
      	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
      	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
      	at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
      	at com.atlassian.greenhopper.service.lexorank.balance.LexoRankBalancer$IndexingRunnable.run(LexoRankBalancer.java:505)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      	at java.lang.Thread.run(Thread.java:745)
      

      Steps to Reproduce

      1. Have an instance of JIRA with a considerable amount of issues. Our testing environment had more than 500.000;
      2. Trigger the re-balance of an Agile LexoRank field;
      3. Perform a project import;

      Workaround

      Even though a rebalance will not prevent the project from being imported, it will delay the process heavily. The only known way to perform the import in a faster pace is to wait for the re-balance to complete before importing projects.

      Attachments

        Issue Links

          Activity

            People

              Unassigned Unassigned
              jpalharini Joao Palharini (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated: