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

Using the Page Index Macro in a Space with thousands of pages takes a long time to complete and may overload the Confluence server

XMLWordPrintable

      Resolution requires the faster permissions service

      To resolve this issue you will need to enable the faster permissions service in your site.

      Issue Summary

      When loading a page with the Page Index Macro, the page takes a long time to render.
      If a timeout is configured (i.e. from a proxy), then the page is not loaded because of it.

      Depending on how many times the macro is loaded at the same time, it may overload the Confluence server and eventually make it unusable.

      Steps to Reproduce

      1. Have a fresh install of Confluence.
      2. Login to Confluence as an admin (part of the confluence-administrators group).
      3. Create a sample Space and add thousands of pages to it.
        • 1k pages is enough as a proof of concept.
        • If you want to add more complexity to the issue, create 4.5k pages.
      4. Create a page in the same space and add the Page Index Macro.
        • When the page is loaded after saving it, the macro will render fast – this occurs because the admin bypass the page restrictions validation.
      5. Login to Confluence as a regular user (not part of the confluence-administrators group).
      6. Access the page with the Page Index Macro.

      Expected Results

      A page with the Page Index Macro will load within an acceptable time and the user won't experience a delay on rendering the macro.

      Actual Results

      The page takes a long time to load, but will eventually.
      In a simple computer, this is the time the macro takes to render depending on the number of pages within the Space:

      Number
      of pages      		 Time (s)
      100 0
      250 0
      500 8
      1,000 32
      2,500 252
      4,998 961

      The results may differ depending on the HW used to run the tests, but it is clear the time to render the macro doesn't scale linearly with the number of pages.

      Notes

      The situation may worsen because the macro is rendered synchronously. That means Confluence must fetch the macro content before retrieving any content to the user's client (browser).
      The user might think the request was not processed and may try to refresh the page or try to access it in other browser windows, triggering new threads that will add more overhead to the Confluence backend.

      Depending on several parameters (number of users trying to access the same page, an user refreshing the page multiple times, complexity of the Space), this macro may create a situation on which the HW resources (CPU, memory) will be highly consumed and eventually bring the instance down (or make it unusable to the users).

      How to identify if affected by this issue

      Taking thread dumps during periods of high load, or before restarting Confluence on the event of an incident, shows one or more HTTP threads stuck with a similar stack trace as below.

      "http-nio-26132-exec-8" #63 daemon prio=5 os_prio=31 tid=0x00007fc57bf64000 nid=0xb503 runnable [0x0000700014981000]
   java.lang.Thread.State: RUNNABLE
(...)
	at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1441)
	at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1410)
	at com.atlassian.confluence.security.persistence.dao.hibernate.HibernateContentPermissionSetDao.lambda$getInheritedContentPermissionSets$2(HibernateContentPermissionSetDao.java:109)
	at com.atlassian.confluence.security.persistence.dao.hibernate.HibernateContentPermissionSetDao$$Lambda$1101/1350530201.doInHibernate(Unknown Source)
	at org.springframework.orm.hibernate5.HibernateTemplate.doExecute(HibernateTemplate.java:361)
	at org.springframework.orm.hibernate5.HibernateTemplate.execute(HibernateTemplate.java:315)
	at com.atlassian.confluence.security.persistence.dao.hibernate.HibernateContentPermissionSetDao.getInheritedContentPermissionSets(HibernateContentPermissionSetDao.java:80)
	at com.atlassian.confluence.core.DefaultInheritedContentPermissionManager.getInheritedContentPermissionSets(DefaultInheritedContentPermissionManager.java:44)
	at com.atlassian.confluence.core.DefaultInheritedContentPermissionManager.getInheritedContentPermissionSetsIncludeEdit(DefaultInheritedContentPermissionManager.java:38)
	at com.atlassian.confluence.core.CachingInheritedContentPermissionManager.queryAndCache(CachingInheritedContentPermissionManager.java:71)
	at com.atlassian.confluence.core.CachingInheritedContentPermissionManager.getInheritedContentPermissionSets(CachingInheritedContentPermissionManager.java:62)
	at com.atlassian.confluence.core.CachingInheritedContentPermissionManager.getInheritedContentPermissionSetsIncludeEdit(CachingInheritedContentPermissionManager.java:45)
	at com.atlassian.confluence.core.DefaultContentPermissionManager.getInheritedContentPermissionSets(DefaultContentPermissionManager.java:155)
	at com.atlassian.confluence.core.DefaultContentPermissionManager.hasInheritedContentLevelViewPermissions(DefaultContentPermissionManager.java:256)
	at com.atlassian.confluence.core.DefaultContentPermissionManager.hasContentLevelPermission(DefaultContentPermissionManager.java:191)
(...)
	at com.sun.proxy.$Proxy213.hasContentLevelPermission(Unknown Source)
	at com.atlassian.confluence.security.delegate.PagePermissionsDelegate.hasContentLevelViewPermission(PagePermissionsDelegate.java:123)
	at com.atlassian.confluence.security.delegate.PagePermissionsDelegate.canView(PagePermissionsDelegate.java:20)
	at com.atlassian.confluence.security.delegate.PagePermissionsDelegate.canView(PagePermissionsDelegate.java:13)
	at com.atlassian.confluence.security.delegate.TargetToLatestVersionDecorator.canView(TargetToLatestVersionDecorator.java:24)
	at com.atlassian.confluence.security.delegate.SharedAccessInterceptor$$Lambda$1490/328114757.test(Unknown Source)
	at com.atlassian.confluence.security.delegate.SharedAccessInterceptor.checkAccess(SharedAccessInterceptor.java:88)
	at com.atlassian.confluence.security.delegate.SharedAccessInterceptor.canView(SharedAccessInterceptor.java:26)
	at com.atlassian.confluence.security.Permission$1.checkAgainst(Permission.java:17)
	at com.atlassian.confluence.security.DefaultPermissionManager.hasPermissionNoExemptions(DefaultPermissionManager.java:100)
	at com.atlassian.confluence.security.DefaultPermissionManager.hasPermission(DefaultPermissionManager.java:48)
	at com.atlassian.confluence.security.DefaultPermissionManager.getPermittedEntities(DefaultPermissionManager.java:149)
	at sun.reflect.GeneratedMethodAccessor2077.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
(...)
	at com.sun.proxy.$Proxy214.getPermittedEntities(Unknown Source)
	at com.atlassian.confluence.plugins.macros.advanced.IndexMacro.fetchPages(IndexMacro.java:126)
	at com.atlassian.confluence.plugins.macros.advanced.IndexMacro.getHtml(IndexMacro.java:86)
	at com.atlassian.confluence.renderer.radeox.macros.AbstractHtmlGeneratingMacro.execute(AbstractHtmlGeneratingMacro.java:46)
	at com.atlassian.renderer.macro.RadeoxCompatibilityMacro.execute(RadeoxCompatibilityMacro.java:149)
	at com.atlassian.confluence.renderer.v2.macros.RadeoxCompatibilityMacro.execute(RadeoxCompatibilityMacro.java:46)
	at com.atlassian.renderer.v2.macro.ResourceAwareMacroDecorator.execute(ResourceAwareMacroDecorator.java:51)
	at com.atlassian.confluence.macro.V2CompatibilityMacro.execute(V2CompatibilityMacro.java:36)
	at com.atlassian.confluence.macro.LazyLoadingMacroWrapper.execute(LazyLoadingMacroWrapper.java:24)
	at com.atlassian.confluence.content.render.xhtml.view.macro.ViewMacroMarshaller.executeMacro(ViewMacroMarshaller.java:255)
(...)
	at com.atlassian.confluence.content.render.xhtml.DefaultRenderer.render(DefaultRenderer.java:110)
	at com.atlassian.confluence.content.render.xhtml.DeviceTypeAwareRenderer.render(DeviceTypeAwareRenderer.java:43)
	at com.atlassian.confluence.pages.actions.ViewPageAction.execute(ViewPageAction.java:270)
	at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:168)
(...)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	- locked <0x0000000789650a78> (a org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)

      Checking what Confluence does on the database, most of the time it is performing queries to validate if the current user has enough permissions to view the pages within the target Space.
      Thousands of queries similar to the ones below may be found in the DB transaction log.

      select contentent2_.CONTENTID as col_0_0_ from CONTENT page0_ left outer join CONFANCESTORS ancestors1_ on page0_.CONTENTID=ancestors1_.DESCENDENTID left outer join CONTENT contentent2_ on ancestors1_.ANCESTORID=contentent2_.CONTENTID where page0_.CONTENTTYPE='PAGE' and page0_.CONTENTID=$1

select contentper0_.ID as ID1_15_, contentper0_.CONT_PERM_TYPE as CONT_PER2_15_, contentper0_.CONTENT_ID as CONTENT_3_15_, contentper0_.CREATIONDATE as CREATION4_15_, contentper0_.LASTMODDATE as LASTMODD5_15_ from CONTENT_PERM_SET contentper0_ where contentper0_.CONT_PERM_TYPE=$1 and (contentper0_.CONTENT_ID in ($2))

      With log profiling enabled you will notice most of the time is spent while doing permission management tasks.

      2019-02-05 16:41:33,842 DEBUG [http-nio-26132-exec-8] [atlassian.util.profiling.UtilTimerStack] log [961657ms] - /c6132/display/SO5000/A+Page+Index+Macro
  [13ms] - UserAccessor.getUserByName()
(...)
      [960243ms] - XW Interceptor: After defaultStack: /pages/viewpage.action (ViewPageAction.execute())
        [960243ms] - XW Interceptor: After validatingStack: /pages/viewpage.action (ViewPageAction.execute())
          [0ms] - UserAccessor.getPropertySet()
          [958024ms] - DefaultRenderer.render
            [958024ms] - DefaultRenderer.renderWithResult
              [0ms] - UserAccessor.getPropertySet()
              [0ms] - UserAccessor.getPropertySet()
              [0ms] - UserAccessor.getPropertySet()
              [0ms] - UserAccessor.getPropertySet()
              [0ms] - SpaceManager.getSpace()
              [5ms] - PageManager.getPageCount()
              [237ms] - PageManager.getPagesWithPermissions()
              [957323ms] - PermissionManager.getPermittedEntities()
              [124ms] - Rendering velocity template: com/atlassian/confluence/plugins/macros/advanced/alphaindex.vm
              [1ms] - UserAccessor.getUserProfilePicture()
              [0ms] - UserAccessor.getPropertySet()
              [0ms] - UserAccessor.getUserProfilePicture()
              [0ms] - UserAccessor.getPropertySet()
(...)

      Workaround

      The Confluence administrator may add the below JVM argument to restrict the macro from running on large spaces:

      -Dpage.index.macro.max.pages=500

      Check this KB to know how to configure system properties.

      Users will still be able to add the macro to pages, but when loading the page, the macro will render a message as the one below without running its background job:

      Note that you must be in one of the versions that fix bug CONFSERVER-55450 to have this functionality working as expected.

        1. space_index_message_img001.png
          space_index_message_img001.png
          56 kB

              glipatov George Lipatov
              tmasutti Thiago Masutti
              Votes:
              15 Vote for this issue
              Watchers:
              33 Start watching this issue

                Created:
                Updated:
                Resolved: