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

            Katherine Yabut made changes -
            Workflow Original: JAC Bug Workflow v3 [ 2888228 ] New: CONFSERVER Bug Workflow v4 [ 2999446 ]
            Owen made changes -
            Workflow Original: JAC Bug Workflow v2 [ 2797526 ] New: JAC Bug Workflow v3 [ 2888228 ]
            Status Original: Resolved [ 5 ] New: Closed [ 6 ]
            Owen made changes -
            Workflow Original: JAC Bug Workflow [ 2727675 ] New: JAC Bug Workflow v2 [ 2797526 ]
            Owen made changes -
            Workflow Original: Confluence Workflow - Public Facing - Restricted v5 - TEMP [ 2392387 ] New: JAC Bug Workflow [ 2727675 ]
            Katherine Yabut made changes -
            Workflow Original: Confluence Workflow - Public Facing - Restricted v5 [ 2288355 ] New: Confluence Workflow - Public Facing - Restricted v5 - TEMP [ 2392387 ]
            Katherine Yabut made changes -
            Workflow Original: Confluence Workflow - Public Facing - Restricted v5.1 - TEMP [ 2227218 ] New: Confluence Workflow - Public Facing - Restricted v5 [ 2288355 ]
            Katherine Yabut made changes -
            Workflow Original: Confluence Workflow - Public Facing - Restricted v5 - TEMP [ 2182555 ] New: Confluence Workflow - Public Facing - Restricted v5.1 - TEMP [ 2227218 ]
            Katherine Yabut made changes -
            Workflow Original: Confluence Workflow - Public Facing - Restricted v5 [ 1950706 ] New: Confluence Workflow - Public Facing - Restricted v5 - TEMP [ 2182555 ]
            Katherine Yabut made changes -
            Workflow Original: Confluence Workflow - Public Facing - Restricted v3 [ 1744400 ] New: Confluence Workflow - Public Facing - Restricted v5 [ 1950706 ]
            Katherine Yabut made changes -
            Workflow Original: CONF Bug Subtask WF (TEMP) [ 1706131 ] New: Confluence Workflow - Public Facing - Restricted v3 [ 1744400 ]

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

                Created:
                Updated:
                Resolved: