Uploaded image for project: 'Confluence Data Center'
  1. Confluence Data Center
  2. CONFSERVER-40399

MySQL reindexing very slow since upgrade

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Support Request
    • Icon: High High
    • None
    • 5.9.3
    • None

      Upgrading a Confluence 5.7.4 to 5.9.3, I'm encountering extremely slow reindexing times.

      The CPU on the MySQL server is spiked very high compared to a reindex on version 5.7.4

      During indexing, it's running some very slow queries:

      mysql> explain select contentent0_.CONTENTID as CONTENTID, contentent0_.CONTENTTYPE as CONTENTT2_, contentent0_.HIBERNATEVERSION as HIBERNAT3_, contentent0_.TITLE as TITLE, contentent0_.VERSION as VERSION, contentent0_.CREATOR as CREATOR, contentent0_.CREATIONDATE as CREATION7_, contentent0_.LASTMODIFIER as LASTMODI8_, contentent0_.LASTMODDATE as LASTMODD9_, contentent0_.VERSIONCOMMENT as VERSION10_, contentent0_.PREVVER as PREVVER, contentent0_.CONTENT_STATUS as CONTENT12_, contentent0_.PAGEID as PAGEID, contentent0_.SPACEID as SPACEID, contentent0_.CHILD_POSITION as CHILD_P15_, contentent0_.PARENTID as PARENTID, contentent0_.MESSAGEID as MESSAGEID, contentent0_.PLUGINKEY as PLUGINKEY, contentent0_.PLUGINVER as PLUGINVER, contentent0_.PARENTCCID as PARENTCCID, contentent0_.DRAFTPAGEID as DRAFTPA21_, contentent0_.DRAFTSPACEKEY as DRAFTSP22_, contentent0_.DRAFTTYPE as DRAFTTYPE, contentent0_.DRAFTPAGEVERSION as DRAFTPA24_, contentent0_.PARENTCOMMENTID as PARENTC25_, contentent0_.USERNAME as USERNAME from CONTENT contentent0_ where (contentent0_.VERSION in(select max(contentent1_.VERSION) from CONTENT contentent1_ where ((contentent1_.PREVVER=16782183 )AND(contentent1_.CONTENT_STATUS='current' ))OR((contentent1_.CONTENTID=16782183 )AND(contentent1_.CONTENT_STATUS='current' )) group by  contentent1_.LASTMODIFIER))AND((contentent0_.PREVVER=16782183 )AND(contentent0_.CONTENT_STATUS='current' ))OR((contentent0_.CONTENTID=16782183 )AND(contentent0_.CONTENT_STATUS='current' )) order by  contentent0_.VERSION asc;
+----+-------------+--------------+------+-------------------------------------------------------+--------------+---------+-------+--------+---------------------------------------------------------------------+
| id | select_type | table        | type | possible_keys                                         | key          | key_len | ref   | rows   | Extra                                                               |
+----+-------------+--------------+------+-------------------------------------------------------+--------------+---------+-------+--------+---------------------------------------------------------------------+
|  1 | PRIMARY     | contentent0_ | ref  | PRIMARY,c_prevver_idx,c_status_idx                    | c_status_idx | 768     | const | 505234 | Using index condition; Using where; Using filesort                  |
|  2 | SUBQUERY    | contentent1_ | ref  | PRIMARY,c_prevver_idx,c_lastmodifier_idx,c_status_idx | c_status_idx | 768     | const | 505234 | Using index condition; Using where; Using temporary; Using filesort |
+----+-------------+--------------+------+-------------------------------------------------------+--------------+---------+-------+--------+---------------------------------------------------------------------+

      Here's one example from MySQL's slow query log:

      # Query_time: 10.333101  Lock_time: 0.000209  Rows_sent: 1  Rows_examined: 2010571  Error_code: 0
SET timestamp=1452036950;
select contentent0_.CONTENTID as CONTENTID, contentent0_.CONTENTTYPE as CONTENTT2_, contentent0_.HIBERNATEVERSION as HIBERNAT3_, contentent0_.TITLE as TITLE, contentent0_.VERSION as VERSION, contentent0_.CREATOR as CREATOR, contentent0_.CREATIONDATE as CREATION7_, contentent0_.LASTMODIFIER as LASTMODI8_, contentent0_.LASTMODDATE as LASTMODD9_, contentent0_.VERSIONCOMMENT as VERSION10_, contentent0_.PREVVER as PREVVER, contentent0_.CONTENT_STATUS as CONTENT12_, contentent0_.PAGEID as PAGEID, contentent0_.SPACEID as SPACEID, contentent0_.CHILD_POSITION as CHILD_P15_, contentent0_.PARENTID as PARENTID, contentent0_.MESSAGEID as MESSAGEID, contentent0_.PLUGINKEY as PLUGINKEY, contentent0_.PLUGINVER as PLUGINVER, contentent0_.PARENTCCID as PARENTCCID, contentent0_.DRAFTPAGEID as DRAFTPA21_, contentent0_.DRAFTSPACEKEY as DRAFTSP22_, contentent0_.DRAFTTYPE as DRAFTTYPE, contentent0_.DRAFTPAGEVERSION as DRAFTPA24_, contentent0_.PARENTCOMMENTID as PARENTC25_, contentent0_.USERNAME as USERNAME from CONTENT contentent0_ where (contentent0_.VERSION in(select max(contentent1_.VERSION) from CONTENT contentent1_ where ((contentent1_.PREVVER=16784251 )AND(contentent1_.CONTENT_STATUS='current' ))OR((contentent1_.CONTENTID=16784251 )AND(contentent1_.CONTENT_STATUS='current' )) group by  contentent1_.LASTMODIFIER))AND((contentent0_.PREVVER=16784251 )AND(contentent0_.CONTENT_STATUS='current' ))OR((contentent0_.CONTENTID=16784251 )AND(contentent0_.CONTENT_STATUS='current' )) order by  contentent0_.VERSION asc;

      The Reindex progress has been stuck at 3% for the last one hour. This doesn't happen in Confluence 5.7.4.

      MySQL version: 5.6.21
      JDBC Driver: 5.1.25

      During the upgrade, I did not see any schema upgrade problems:

      2016-01-04 22:35:25,606 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] contextInitialized Starting Confluence 5.9.3 [build 6210 based on commit hash 96b66f73363ad6a4132228b496713b1df46ada86]
2016-01-04 22:35:29,125 INFO [localhost-startStop-1] [springframework.web.context.ContextLoader] initWebApplicationContext Root WebApplicationContext: initialization started
2016-01-04 22:35:34,184 INFO [localhost-startStop-1] [com.atlassian.confluence.lifecycle] <init> Loading EhCache cache manager
2016-01-04 22:35:36,612 WARN [localhost-startStop-1] [org.springframework.beans.TypeConverterDelegate] findDefaultEditor PropertyEditor [com.sun.beans.editors.EnumEditor] found through deprecated global PropertyEditorManager fallback - consider using a more isolated form of registration, e.g. on the BeanWrapper/BeanFactory!
2016-01-04 22:35:44,695 WARN [localhost-startStop-1] [org.springframework.beans.TypeConverterDelegate] findDefaultEditor PropertyEditor [com.sun.beans.editors.EnumEditor] found through deprecated global PropertyEditorManager fallback - consider using a more isolated form of registration, e.g. on the BeanWrapper/BeanFactory!
2016-01-04 22:35:44,701 WARN [localhost-startStop-1] [org.springframework.beans.TypeConverterDelegate] findDefaultEditor PropertyEditor [com.sun.beans.editors.EnumEditor] found through deprecated global PropertyEditorManager fallback - consider using a more isolated form of registration, e.g. on the BeanWrapper/BeanFactory!
2016-01-04 22:35:46,910 INFO [localhost-startStop-1] [springframework.web.context.ContextLoader] initWebApplicationContext Root WebApplicationContext: initialization completed in 17784 ms
2016-01-04 22:35:48,607 WARN [localhost-startStop-1] [confluence.setup.dbcheck.MySQLChecker] checkCharacterSetAndCollation Your database uses non-recommended collation: utf8_general_ci. See https://confluence.atlassian.com/x/IrYC
2016-01-04 22:35:48,643 INFO [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] earlyStartup Plugin system earlyStartup begun
2016-01-04 22:36:01,795 WARN [localhost-startStop-1] [factory.transform.stage.ScanDescriptorForHostClassesStage] execute The plugin '1395279836000plugin.400638095808414329.atlassian-universal-plugin-manager-plugin-2.15.2.jar' uses a package 'org.apache.commons.fileupload.servlet' that is also exported by the application.  It is highly recommended that the plugin use its own packages.
2016-01-04 22:36:19,412 WARN [localhost-startStop-1] [confluence.plugin.descriptor.MacroMetadataParser] parseParameter Unrecognised type 'integer' for parameter 'version' of macro 'gliffy' in plugin 'com.gliffy.integration.confluence'
2016-01-04 22:36:22,822 WARN [ThreadPoolAsyncTaskExecutor::Thread 5] [spring.scanner.util.ProductFilterUtil] detectProduct Couldn't detect product, will use ProductFilter.ALL
2016-01-04 22:36:24,282 WARN [ThreadPoolAsyncTaskExecutor::Thread 5] [spring.scanner.util.ProductFilterUtil] detectProduct Couldn't detect product, will use ProductFilter.ALL
2016-01-04 22:36:24,344 WARN [ThreadPoolAsyncTaskExecutor::Thread 15] [spring.scanner.util.ProductFilterUtil] detectProduct Couldn't detect product, will use ProductFilter.ALL
2016-01-04 22:36:24,478 WARN [ThreadPoolAsyncTaskExecutor::Thread 15] [spring.scanner.util.ProductFilterUtil] detectProduct Couldn't detect product, will use ProductFilter.ALL
2016-01-04 22:36:24,521 WARN [ThreadPoolAsyncTaskExecutor::Thread 5] [spring.scanner.util.ProductFilterUtil] detectProduct Couldn't detect product, will use ProductFilter.ALL
2016-01-04 22:36:33,211 INFO [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] earlyStartup Plugin system earlyStartup finished in 0:00:44.564
2016-01-04 22:38:14,741 INFO [localhost-startStop-1] [confluence.upgrade.upgradetask.DropSpaceGroupTablesUpgradeTask] doUpgrade Starting dropping unused column SPACES.SPACEGROUPID, table SPACEGROUPPERMISSIONS, and table SPACEGROUPS
2016-01-04 22:38:17,208 INFO [localhost-startStop-1] [confluence.upgrade.upgradetask.DropSpaceGroupTablesUpgradeTask] doUpgrade Finished dropping unused column SPACES.SPACEGROUPID, table SPACEGROUPPERMISSIONS, and table SPACEGROUPS
2016-01-04 22:38:17,238 INFO [localhost-startStop-1] [confluence.upgrade.ddl.HibernateAlterTableExecutor] alterTable Executing grouped alter table command on USERCONTENT_RELATION
2016-01-04 22:38:17,240 INFO [localhost-startStop-1] [confluence.upgrade.ddl.HibernateDdlExecutor] executeDdlStatements Executing DDL: alter table USERCONTENT_RELATION add constraint u2c_relation_unique unique (TARGETCONTENTID, SOURCEUSER, RELATIONNAME)
2016-01-04 22:38:17,372 INFO [localhost-startStop-1] [confluence.upgrade.ddl.HibernateAlterTableExecutor] alterTable Executing grouped alter table command on CONTENT_RELATION
2016-01-04 22:38:17,373 INFO [localhost-startStop-1] [confluence.upgrade.ddl.HibernateDdlExecutor] executeDdlStatements Executing DDL: alter table CONTENT_RELATION add constraint c2c_relation_unique unique (TARGETCONTENTID, SOURCECONTENTID, RELATIONNAME)
2016-01-04 22:38:17,482 INFO [localhost-startStop-1] [confluence.upgrade.ddl.HibernateAlterTableExecutor] alterTable Executing grouped alter table command on USER_RELATION
2016-01-04 22:38:17,483 INFO [localhost-startStop-1] [confluence.upgrade.ddl.HibernateDdlExecutor] executeDdlStatements Executing DDL: alter table USER_RELATION add constraint u2u_relation_unique unique (SOURCEUSER, TARGETUSER, RELATIONNAME)
2016-01-04 22:38:18,099 INFO [localhost-startStop-1] [atlassian.confluence.upgrade.AbstractUpgradeManager] upgradeStarted Starting automatic upgrade of Confluence
2016-01-04 22:38:18,968 INFO [localhost-startStop-1] [upgrade.upgradetask.attachmentceo.AttachmentContentStatusUpgradeTask] doUpgrade Fixing attachments with missing content status...
2016-01-04 22:38:33,865 INFO [localhost-startStop-1] [upgrade.upgradetask.attachmentceo.AttachmentContentStatusUpgradeTask] doUpgrade Updated the status of 119741 attachment entries
2016-01-04 22:38:33,909 INFO [localhost-startStop-1] [confluence.upgrade.upgradetask.RemoveConfluenceThreadDumpPluginUpgradeTask] doUpgrade Starting to uninstall the Confluence Thread Dump Plugin
2016-01-04 22:38:33,911 INFO [localhost-startStop-1] [confluence.upgrade.upgradetask.RemoveConfluenceThreadDumpPluginUpgradeTask] doUpgrade Finished uninstalling the Confluence Thread Dump Plugin
2016-01-04 22:38:33,954 INFO [localhost-startStop-1] [confluence.upgrade.upgradetask.UserIndexingUpgradeTask] doUpgrade Beginning User Indexing repair.
2016-01-04 22:38:33,955 INFO [localhost-startStop-1] [confluence.upgrade.upgradetask.UserIndexingUpgradeTask] doUpgrade Scheduling reindexing of existing users
2016-01-04 22:38:34,018 INFO [localhost-startStop-1] [confluence.upgrade.upgradetask.UserIndexingUpgradeTask] doUpgrade Retrieving the userkeys and matching Personal Information from db...
2016-01-04 22:38:34,120 INFO [localhost-startStop-1] [confluence.upgrade.upgradetask.UserIndexingUpgradeTask] doUpgrade Found 0 userkeys that need PersonalInformation created.
2016-01-04 22:38:34,122 INFO [localhost-startStop-1] [confluence.upgrade.upgradetask.UserIndexingUpgradeTask] doUpgrade Finished User Indexing repair.
2016-01-04 22:38:34,144 INFO [localhost-startStop-1] [confluence.upgrade.upgradetask.AddSpacePermissionSubjectColumnUpgradeTask] doUpgrade Adding SpacePermission subject column
2016-01-04 22:38:34,174 INFO [localhost-startStop-1] [confluence.upgrade.upgradetask.ContentIndexUpgradeTask] doUpgrade Adding a multi-column index to content table
2016-01-04 22:38:34,175 INFO [localhost-startStop-1] [confluence.upgrade.ddl.HibernateDdlExecutor] executeDdlStatements Executing DDL: create index c_si_ct_pv_cs_cd_idx on CONTENT (SPACEID, CONTENTTYPE, PREVVER, CONTENT_STATUS, CREATIONDATE)
2016-01-04 22:38:41,510 INFO [localhost-startStop-1] [atlassian.confluence.upgrade.AbstractUpgradeManager] initialUpgradeFinished Upgrade initial stage completed successfully
2016-01-04 22:38:41,512 INFO [localhost-startStop-1] [atlassian.plugin.manager.DefaultPluginManager] lateStartup Plugin system lateStartup begun

            [CONFSERVER-40399] MySQL reindexing very slow since upgrade

            David Yu added a comment -

            Support opened a new bug for us at CONF-40544. Go watch that one.

            David Yu added a comment - Support opened a new bug for us at CONF-40544 . Go watch that one.

            Oleksandr Rybchenko added a comment -

            Same problem.
            Please help

            Oleksandr Rybchenko added a comment - Same problem. Please help

            Doug added a comment -

            We are also experiencing a very slow reindexing problem. Our developer environment went from 40 minutes to reindex 5.8.13 to what we calculate to be 86 hours to reindex 5.9.4.

            Doug added a comment - We are also experiencing a very slow reindexing problem. Our developer environment went from 40 minutes to reindex 5.8.13 to what we calculate to be 86 hours to reindex 5.9.4.

            John Love added a comment - - edited

            Thanks! Our instance isn't huge, but, but what took around 20 minutes in 5.8.x has now been running for over 2.5 hours (gave up once and restarted Confluence) and it's only 53% done. Oddly, the instance itself seems to be running OK, but I am the only one on it at the moment.

            John Love added a comment - - edited Thanks! Our instance isn't huge, but, but what took around 20 minutes in 5.8.x has now been running for over 2.5 hours (gave up once and restarted Confluence) and it's only 53% done. Oddly, the instance itself seems to be running OK, but I am the only one on it at the moment.

            David Yu added a comment - - edited

            Still none--trying to convince support to have a developer review this. Minh, can this get reopened? You've now got three reports of this.

            David Yu added a comment - - edited Still none--trying to convince support to have a developer review this. Minh, can this get reopened? You've now got three reports of this.

            John Love added a comment -

            Same issue here with 5.9.3. What is the resolution?

            John Love added a comment - Same issue here with 5.9.3. What is the resolution?

            Minh Tran added a comment -

            Dear davidrr,

            Thanks for raising this issue. I believe this is something that our support team will be able to help you with.
            Could I ask that you create a support ticket on https://support.atlassian.com?
            Once you've done this one of our support engineers will be in touch to work with you in resolving this problem.

            Regards,
            Minh Tran
            Confluence Bugmaster
            Atlassian

            Minh Tran added a comment - Dear davidrr , Thanks for raising this issue. I believe this is something that our support team will be able to help you with. Could I ask that you create a support ticket on https://support.atlassian.com ? Once you've done this one of our support engineers will be in touch to work with you in resolving this problem. Regards, Minh Tran Confluence Bugmaster Atlassian

              Unassigned Unassigned
              a38518e05741 David Yu
              Affected customers:
              0 This affects my team
              Watchers:
              12 Start watching this issue

                Created:
                Updated:
                Resolved: