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

Creating or deleting page comments in pages with several watchers might be slow

    XMLWordPrintable

Details

    Description

      Issue Summary

      Depending on the number of watchers in a page (space watchers as well), creating or deleting page comments can take several seconds.
      This happens because Confluence is processing notifications in the same thread as the one that triggered the action in the UI.
      This might create an awful UI experience to the Confluence user, giving the impression the operation is not being executed.
      The situation may worsen depending on user directory complexity, such as when nested groups are enabled and heavily used to configure space permissions and page restrictions.

      The same occurs when adding or removing inline comments.

      Environment

      This issue was validated on a vanilla Confluence Server on version 6.13.3.

      Steps to Reproduce

      Creating a Page Comment
      1. Install a Confluence vanilla instance.
      2. Create 2,000 regular users in the internal directory that are part of confluence-users group.
        • The following shell script may help automating that task. 
          USRNAME=admin
USRPWD=admin
CONFBASEURL=http://localhost:26133/c6133

for i in $(seq 1 2000); do
 NEW_USRNAME=test_user$i
 NEW_USR_FULLNAME="Test User $i"
 NEW_USR_EMAIL="test_user"$i"@user.com"
 NEW_USR_PWD=test_user$i

 curl --user $USRNAME:$USRPWD -H "Content-Type: application/json" -H "Accept: application/json" -X POST -d "{ \"jsonrpc\" : \"2.0\", \"method\" : \"addUser\", \"params\" : [{\"name\" : \"$NEW_USRNAME\", \"fullname\" : \"$NEW_USR_FULLNAME\", \"email\" : \"$NEW_USR_EMAIL\"}, \"$NEW_USR_PWD\"], \"id\": 7 }" $CONFBASEURL/rpc/json-rpc/confluenceservice-v2?os_authType=basic >/dev/null 2>&1
done
      3. As the Confluence administrator, create a sample Blank Space – let's call it Test Space.
      4. In Test Space create a sample Blank Page – let's call it Page with 2000 watchers.
      5. Add the 2,000 regular users as watchers of Page with 2000 watchers.
        • The following shell script may help automating this task. 
          USRNAME=admin
USRPWD=admin
CONFBASEURL=http://localhost:26133/c6133
PAGEID=3540960

#######
# Change the following with actual values
# <ADD FULL COOKIE STRING>
# <ATL TOKEN>
#######
for i in $(seq 1 2000); do
WATCHER_USRNAME=test_user$i
curl $CONFBASEURL'/json/addwatch.action' -H 'Accept: application/json, text/javascript, */*; q=0.01' -H 'Accept-Language: en-US,en;q=0.5' -H 'Content-Type: application/x-www-form-urlencoded; charset=UTF-8' -H 'X-Requested-With: XMLHttpRequest' -H 'Connection: keep-alive' -H 'Cookie: <ADD FULL COOKIE STRING>' -H 'Pragma: no-cache' -H 'Cache-Control: no-cache' --data 'atl_token=<ATL TOKEN>&pageId='$PAGEID'&type=page&username='$WATCHER_USRNAME >/dev/null 2>&1
done
      6. Log in to Confluence UI as a regular user and access Page with 2000 watchers.
      7. Write a Page Comment and click on Save.
      Expected Results

      The comment is created almost instantly and the UI is released to the user to continue its work on Confluence.

      Actual Results

      After clicking on Save, the operation takes a long time, giving to the user a spinning wheel in the comment editor.

      Eventually, the operation completes and the user perceives that by seeing the comment in the Page.

      Checking the HAR file generated while reproducing this use case shows a POST request to <Confluence Base URL>/rest/tinymce/1/content/{{pageID/comment?actions=true}} takes too long.

      If Page Profiling is enabled, then a similar entry to the following is logged in atlassian-confluence.log, but we don't have information on what is causing the long time to complete it:

      2019-05-23 13:06:29,116 DEBUG [http-nio-26133-exec-10] [atlassian.util.profiling.UtilTimerStack] log [66087ms] - /c6133/rest/tinymce/1/content/4096007/comment
  [0ms] - UserAccessor.getExistingUserByKey()
  [0ms] - ContentEntityManager.getById()
  [1ms] - PermissionManager.hasCreatePermission()
    [0ms] - UserAccessor.isDeactivated()
      [0ms] - CrowdService.getUser()
        [0ms] - ApplicationDAO.findByName()
        [0ms] - UserDao.findByName()
    [0ms] - CrowdService.isUserMemberOfGroup()
      [0ms] - ApplicationDAO.findByName()
      [0ms] - MembershipDao.isUserDirectMember()
      [0ms] - MembershipDao.isUserDirectMember()
      [0ms] - MembershipDao.search()
    [0ms] - UserAccessor.isDeactivated()
    [0ms] - CrowdService.isUserMemberOfGroup()
      [0ms] - ApplicationDAO.findByName()
      [0ms] - MembershipDao.isUserDirectMember()
      [0ms] - MembershipDao.isUserDirectMember()
      [0ms] - MembershipDao.search()
    [0ms] - CrowdService.isUserMemberOfGroup()
      [0ms] - ApplicationDAO.findByName()
      [0ms] - MembershipDao.isUserDirectMember()
    [0ms] - DefaultSpacePermissionManager.hasPermissionNoExemptions(VIEWSPACE, regular_user001, TS1)
      [0ms] - CrowdService.isUserMemberOfGroup()
        [0ms] - ApplicationDAO.findByName()
        [0ms] - MembershipDao.isUserDirectMember()
    [0ms] - DefaultSpacePermissionManager.hasPermissionNoExemptions(COMMENT, regular_user001, TS1)
      [0ms] - CrowdService.isUserMemberOfGroup()
        [0ms] - ApplicationDAO.findByName()
        [0ms] - MembershipDao.isUserDirectMember()
  [0ms] - ContentEntityManager.getById()
  [0ms] - ContentEntityManager.getById()
  [0ms] - ContentEntityManager.getById()

      If thread dumps are taken while the action is being processed, then a stack trace similar to the one below can be found:

      "http-nio-26133-exec-10" #226 daemon prio=5 os_prio=31 tid=0x00007fe9fdaea800 nid=0x1c003 runnable [0x000070001886c000]
   java.lang.Thread.State: RUNNABLE
	at org.hibernate.tuple.entity.AbstractEntityTuplizer.getPropertyValues(AbstractEntityTuplizer.java:603)
	at org.hibernate.tuple.entity.PojoEntityTuplizer.getPropertyValues(PojoEntityTuplizer.java:215)
	at org.hibernate.persister.entity.AbstractEntityPersister.getPropertyValues(AbstractEntityPersister.java:4707)
	at org.hibernate.event.internal.DefaultFlushEntityEventListener.getValues(DefaultFlushEntityEventListener.java:178)
	at org.hibernate.event.internal.DefaultFlushEntityEventListener.onFlushEntity(DefaultFlushEntityEventListener.java:135)
	at org.hibernate.event.internal.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:216)
	at org.hibernate.event.internal.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:85)
	at org.hibernate.event.internal.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:44)
	at org.hibernate.internal.SessionImpl.autoFlushIfRequired(SessionImpl.java:1389)
	at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1882)
	at org.hibernate.internal.CriteriaImpl.list(CriteriaImpl.java:366)
	at org.hibernate.internal.CriteriaImpl.uniqueResult(CriteriaImpl.java:388)
	at com.atlassian.crowd.embedded.hibernate2.HibernateUserDao.lambda$internalFindUser$20(HibernateUserDao.java:544)
	at com.atlassian.crowd.embedded.hibernate2.HibernateUserDao$$Lambda$1288/1825113255.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.crowd.embedded.hibernate2.HibernateUserDao.internalFindUser(HibernateUserDao.java:541)
	at com.atlassian.crowd.embedded.hibernate2.HibernateUserDao.internalFindByName(HibernateUserDao.java:454)
	at com.atlassian.crowd.embedded.hibernate2.HibernateUserDao.findByName(HibernateUserDao.java:437)
	at com.atlassian.confluence.user.crowd.CachedCrowdUserDao.lambda$getUserCache$0(CachedCrowdUserDao.java:76)
	at com.atlassian.confluence.user.crowd.CachedCrowdUserDao$$Lambda$118/1009356644.load(Unknown Source)
	at com.atlassian.cache.impl.CacheLoaderSupplier.get(CacheLoaderSupplier.java:24)
	at com.atlassian.confluence.cache.DeferredOperationsCache.getOrLoad(DeferredOperationsCache.java:113)
	at com.atlassian.confluence.cache.DeferredOperationsCache.get(DeferredOperationsCache.java:61)
	at com.atlassian.confluence.cache.TransactionalCacheFactory$TransactionAwareCache.get(TransactionalCacheFactory.java:341)
	at com.atlassian.confluence.user.crowd.CachedCrowdUserDao.findUser(CachedCrowdUserDao.java:108)
	at com.atlassian.confluence.user.crowd.CachedCrowdUserDao.findByName(CachedCrowdUserDao.java:118)
	at sun.reflect.GeneratedMethodAccessor842.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
(...)
	at com.sun.proxy.$Proxy82.findByName(Unknown Source)
	at com.atlassian.crowd.directory.AbstractInternalDirectory.findUserByName(AbstractInternalDirectory.java:160)
	at com.atlassian.crowd.directory.AbstractInternalDirectory.findUserByName(AbstractInternalDirectory.java:62)
	at com.atlassian.crowd.manager.directory.DirectoryManagerGeneric.findUserByName(DirectoryManagerGeneric.java:283)
	at com.atlassian.crowd.manager.application.ApplicationServiceGeneric.findUserByName(ApplicationServiceGeneric.java:306)
	at com.atlassian.crowd.embedded.core.CrowdServiceImpl.getUser(CrowdServiceImpl.java:86)
	at sun.reflect.GeneratedMethodAccessor822.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
(...)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
	at com.sun.proxy.$Proxy90.getUser(Unknown Source)
	at com.atlassian.crowd.embedded.atlassianuser.EmbeddedCrowdUserManager.getUser(EmbeddedCrowdUserManager.java:107)
(...)
	at com.sun.proxy.$Proxy110.isDeactivated(Unknown Source)
	at com.atlassian.confluence.security.access.DefaultConfluenceAccessManager.getUserAccessStatusNoExemptions(DefaultConfluenceAccessManager.java:51)
	at com.atlassian.confluence.security.access.CachingConfluenceAccessManager.getUserAccessStatusNoExemptions(CachingConfluenceAccessManager.java:38)
	at sun.reflect.GeneratedMethodAccessor706.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
(...)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
	at com.sun.proxy.$Proxy97.getUserAccessStatusNoExemptions(Unknown Source)
	at com.atlassian.confluence.security.DefaultPermissionManager.canUseConfluence(DefaultPermissionManager.java:140)
	at com.atlassian.confluence.security.DefaultPermissionManager.hasPermissionNoExemptions(DefaultPermissionManager.java:92)
	at sun.reflect.GeneratedMethodAccessor1215.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
(...)
	at com.sun.proxy.$Proxy100.hasPermissionNoExemptions(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor1215.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.atlassian.plugin.util.ContextClassLoaderSettingInvocationHandler.invoke(ContextClassLoaderSettingInvocationHandler.java:26)
	at com.sun.proxy.$Proxy222.hasPermissionNoExemptions(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor1215.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.atlassian.plugin.osgi.bridge.external.HostComponentFactoryBean$DynamicServiceInvocationHandler.invoke(HostComponentFactoryBean.java:136)
	at com.sun.proxy.$Proxy222.hasPermissionNoExemptions(Unknown Source)
	at com.atlassian.mywork.providers.confluence.ConfluenceEventListener.lambda$onCommentEvent$1(ConfluenceEventListener.java:234)
	at com.atlassian.mywork.providers.confluence.ConfluenceEventListener$$Lambda$1986/1714476239.test(Unknown Source)
	at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:174)
	at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1382)
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481)
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471)
	at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
	at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:418)
	at com.atlassian.mywork.providers.confluence.ConfluenceEventListener.onCommentEvent(ConfluenceEventListener.java:235)
	at com.atlassian.mywork.providers.confluence.ConfluenceEventListener.onCommentCreatedEvent(ConfluenceEventListener.java:194)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.atlassian.event.internal.SingleParameterMethodListenerInvoker.invoke(SingleParameterMethodListenerInvoker.java:40)
	at com.atlassian.confluence.event.ConfluenceListenerHandlersConfiguration$TimingListenerHandler$1$1.invoke(ConfluenceListenerHandlersConfiguration.java:69)
	at com.atlassian.confluence.event.ConfluenceEventDispatcher$VCacheRequestContextRunnableFactory$1.lambda$run$0(ConfluenceEventDispatcher.java:93)
	at com.atlassian.confluence.event.ConfluenceEventDispatcher$VCacheRequestContextRunnableFactory$1$$Lambda$394/188655259.run(Unknown Source)
	at com.atlassian.confluence.vcache.VCacheRequestContextOperations.lambda$doInRequestContext$0(VCacheRequestContextOperations.java:50)
	at com.atlassian.confluence.vcache.VCacheRequestContextOperations$$Lambda$395/379869065.perform(Unknown Source)
	at com.atlassian.confluence.impl.vcache.VCacheRequestContextManager.doInRequestContextInternal(VCacheRequestContextManager.java:87)
	at com.atlassian.confluence.impl.vcache.VCacheRequestContextManager.doInRequestContext(VCacheRequestContextManager.java:71)
	at com.atlassian.confluence.vcache.VCacheRequestContextOperations.doInRequestContext(VCacheRequestContextOperations.java:49)
	at com.atlassian.confluence.event.ConfluenceEventDispatcher$VCacheRequestContextRunnableFactory$1.run(ConfluenceEventDispatcher.java:93)
	at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:457)
	at com.atlassian.event.internal.AsynchronousAbleEventDispatcher.dispatch(AsynchronousAbleEventDispatcher.java:88)
	at com.atlassian.event.internal.EventPublisherImpl.invokeListeners(EventPublisherImpl.java:203)
	at com.atlassian.event.internal.EventPublisherImpl.publish(EventPublisherImpl.java:114)
	at com.atlassian.confluence.event.TimingEventPublisher.publish(TimingEventPublisher.java:64)
	at com.atlassian.confluence.pages.DefaultCommentManager.saveComment(DefaultCommentManager.java:132)
	at com.atlassian.confluence.pages.DefaultCommentManager.addCommentToObject(DefaultCommentManager.java:109)
(...)
	at com.sun.proxy.$Proxy138.addCommentToObject(Unknown Source)
	at com.atlassian.confluence.content.service.comment.CreateCommentCommandImpl.executeInternal(CreateCommentCommandImpl.java:82)
	at com.atlassian.confluence.core.service.AbstractServiceCommand$ServiceCommandState$2.execute(AbstractServiceCommand.java:148)
	at com.atlassian.confluence.core.service.AbstractServiceCommand.execute(AbstractServiceCommand.java:60)
(...)
	at com.sun.proxy.$Proxy2789.execute(Unknown Source)
	at com.atlassian.confluence.tinymceplugin.rest.PageResource.createOrEditAndRender(PageResource.java:330)
	at com.atlassian.confluence.tinymceplugin.rest.PageResource.add(PageResource.java:289)
	at com.atlassian.confluence.tinymceplugin.rest.PageResource.add(PageResource.java:251)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
      Deleting a Page Comment
      1. Continue from the last step in the Creating a Page Comment Section.
      2. Logged as a regular user, click on the Delete button related to the recently added comment.
      3. Click on the OK button in the pop-up with the confirmation question.
      Expected Results

      The comment is deleted almost instantly and the user gets an obvious confirmation in the UI with the comment removed from the page.

      Actual Results

      Clicking on the Delete button triggers the delete action, but nothing changes in the UI so it gives the wrong impression to the user.
      Refreshing the page shows the comment is still there what may trick the user on clicking the Delete button again.

      If a HAR file is generated while reproducing the problem, then a DELETE request to <Confluence Base URL>/rest/api/content/<comment ID> takes a long time to complete.
      In the backend side the delete operation is on-going, but it takes a long time to complete.

      If Page Profiling is enabled, then a similar entry to the following is logged in atlassian-confluence.log, but we don't have information on what is causing the long time to complete it:

      2019-05-23 14:14:36,495 DEBUG [http-nio-26133-exec-2] [atlassian.util.profiling.UtilTimerStack] log [76524ms] - /c6133/rest/api/content/4096010
  [1ms] - UserAccessor.getExistingUserByKey()
  [1ms] - ContentEntityManagerInternal.getById()
  [0ms] - PermissionManager.hasPermission()
    [0ms] - UserAccessor.isDeactivated()
      [0ms] - CrowdService.getUser()
        [0ms] - ApplicationDAO.findByName()
        [0ms] - UserDao.findByName()
    [0ms] - CrowdService.isUserMemberOfGroup()
      [0ms] - ApplicationDAO.findByName()
      [0ms] - MembershipDao.isUserDirectMember()
      [0ms] - MembershipDao.isUserDirectMember()
      [0ms] - MembershipDao.search()
    [0ms] - UserAccessor.isDeactivated()
    [0ms] - CrowdService.isUserMemberOfGroup()
      [0ms] - ApplicationDAO.findByName()
      [0ms] - MembershipDao.isUserDirectMember()
      [0ms] - MembershipDao.isUserDirectMember()
      [0ms] - MembershipDao.search()
    [0ms] - CrowdService.isUserMemberOfGroup()
      [0ms] - ApplicationDAO.findByName()
      [0ms] - MembershipDao.isUserDirectMember()
    [0ms] - DefaultSpacePermissionManager.hasPermissionNoExemptions(VIEWSPACE, regular_user001, TS1)
      [0ms] - CrowdService.isUserMemberOfGroup()
        [0ms] - ApplicationDAO.findByName()
        [0ms] - MembershipDao.isUserDirectMember()
  [0ms] - ContentEntityManagerInternal.getById()
  [0ms] - PermissionManager.hasPermission()
  [0ms] - UserAccessor.getUserProfilePicture()
  [0ms] - UserAccessor.getUserProfilePicture()
  [7ms] - CommentManager.getComment()
  [2ms] - PermissionManager.hasPermission()
    [0ms] - DefaultSpacePermissionManager.hasPermissionNoExemptions(REMOVECOMMENT, regular_user001, TS1)
  [0ms] - CommentManager.getComment()
  [0ms] - PermissionManager.hasPermission()

      If thread dumps are taken while the operation is still running in the Confluence server, then a stack trace similar to the one below is found:

      "http-nio-26133-exec-5" #221 daemon prio=5 os_prio=31 tid=0x00007fea00736000 nid=0x19803 runnable [0x000070001835b000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.Throwable.fillInStackTrace(Native Method)
	at java.lang.Throwable.fillInStackTrace(Throwable.java:783)
	- locked <0x00000007a353f210> (a java.lang.IllegalArgumentException)
	at java.lang.Throwable.<init>(Throwable.java:287)
	at java.lang.Exception.<init>(Exception.java:84)
	at java.lang.RuntimeException.<init>(RuntimeException.java:80)
	at java.lang.IllegalArgumentException.<init>(IllegalArgumentException.java:72)
	at cz.vutbr.web.csskit.TermFactoryImpl.convertInteger(TermFactoryImpl.java:246)
	at cz.vutbr.web.csskit.TermFactoryImpl.createInteger(TermFactoryImpl.java:102)
	at cz.vutbr.web.csskit.TermFactoryImpl.createNumeric(TermFactoryImpl.java:139)
	at cz.vutbr.web.csskit.antlr.CSSTreeParser.valuepart(CSSTreeParser.java:1876)
	at cz.vutbr.web.csskit.antlr.CSSTreeParser.term(CSSTreeParser.java:1588)
	at cz.vutbr.web.csskit.antlr.CSSTreeParser.terms(CSSTreeParser.java:1490)
	at cz.vutbr.web.csskit.antlr.CSSTreeParser.declaration(CSSTreeParser.java:1320)
	at cz.vutbr.web.csskit.antlr.CSSTreeParser.declarations(CSSTreeParser.java:1196)
	at cz.vutbr.web.csskit.antlr.CSSTreeParser.ruleset(CSSTreeParser.java:1130)
	at cz.vutbr.web.csskit.antlr.CSSTreeParser.statement(CSSTreeParser.java:524)
	at cz.vutbr.web.csskit.antlr.CSSTreeParser.stylesheet(CSSTreeParser.java:431)
	at cz.vutbr.web.csskit.antlr.CSSParserFactory$SourceType$2.parse(CSSParserFactory.java:95)
	at cz.vutbr.web.csskit.antlr.CSSParserFactory.parse(CSSParserFactory.java:230)
	at cz.vutbr.web.csskit.antlr.CSSParserFactory.parse(CSSParserFactory.java:258)
	at cz.vutbr.web.css.CSSFactory.parse(CSSFactory.java:369)
	at com.atlassian.botocss.BotocssStyles.parse(BotocssStyles.java:39)
	at com.atlassian.botocss.Botocss.inject(Botocss.java:134)
	at com.atlassian.confluence.mail.BotocssMailContentProcessor.process(BotocssMailContentProcessor.java:59)
	at com.atlassian.confluence.mail.DefaultMailContentProcessor.process(DefaultMailContentProcessor.java:21)
	at com.atlassian.confluence.mail.template.AbstractMailNotificationQueueItem.transformForEmail(AbstractMailNotificationQueueItem.java:256)
	at com.atlassian.confluence.mail.template.AbstractMailNotificationQueueItem.preRenderBody(AbstractMailNotificationQueueItem.java:200)
	at com.atlassian.confluence.mail.template.PreRenderedMailNotificationQueueItem$Builder.render(PreRenderedMailNotificationQueueItem.java:480)
	at com.atlassian.confluence.mail.notification.DefaultNotificationsSender.createNotificationTask(DefaultNotificationsSender.java:318)
	at com.atlassian.confluence.mail.notification.DefaultNotificationsSender.lambda$sendNotification$0(DefaultNotificationsSender.java:222)
	at com.atlassian.confluence.mail.notification.DefaultNotificationsSender$$Lambda$2013/849262152.call(Unknown Source)
	at com.atlassian.confluence.user.AuthenticatedUserImpersonator$2.call(AuthenticatedUserImpersonator.java:118)
	at com.atlassian.confluence.user.AuthenticatedUserImpersonator$1.call(AuthenticatedUserImpersonator.java:101)
	at com.atlassian.confluence.user.AuthenticatedUserImpersonator.asUser(AuthenticatedUserImpersonator.java:82)
	at com.atlassian.confluence.mail.notification.DefaultNotificationsSender.sendNotification(DefaultNotificationsSender.java:145)
	at com.atlassian.confluence.mail.notification.DefaultNotificationsSender.sendNotification(DefaultNotificationsSender.java:127)
	at com.atlassian.confluence.mail.notification.DefaultNotificationsSender.sendNotifications(DefaultNotificationsSender.java:265)
	at com.atlassian.confluence.mail.notification.DefaultNotificationsSender.sendPageNotifications(DefaultNotificationsSender.java:236)
	at com.atlassian.confluence.mail.notification.listeners.CommentNotificationsListener.handleCommentRemove(CommentNotificationsListener.java:72)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.atlassian.event.internal.SingleParameterMethodListenerInvoker.invoke(SingleParameterMethodListenerInvoker.java:40)
	at com.atlassian.confluence.event.ConfluenceListenerHandlersConfiguration$TimingListenerHandler$1$1.invoke(ConfluenceListenerHandlersConfiguration.java:69)
	at com.atlassian.confluence.event.ConfluenceEventDispatcher$VCacheRequestContextRunnableFactory$1.lambda$run$0(ConfluenceEventDispatcher.java:93)
	at com.atlassian.confluence.event.ConfluenceEventDispatcher$VCacheRequestContextRunnableFactory$1$$Lambda$394/188655259.run(Unknown Source)
	at com.atlassian.confluence.vcache.VCacheRequestContextOperations.lambda$doInRequestContext$0(VCacheRequestContextOperations.java:50)
	at com.atlassian.confluence.vcache.VCacheRequestContextOperations$$Lambda$395/379869065.perform(Unknown Source)
	at com.atlassian.confluence.impl.vcache.VCacheRequestContextManager.doInRequestContextInternal(VCacheRequestContextManager.java:87)
	at com.atlassian.confluence.impl.vcache.VCacheRequestContextManager.doInRequestContext(VCacheRequestContextManager.java:71)
	at com.atlassian.confluence.vcache.VCacheRequestContextOperations.doInRequestContext(VCacheRequestContextOperations.java:49)
	at com.atlassian.confluence.event.ConfluenceEventDispatcher$VCacheRequestContextRunnableFactory$1.run(ConfluenceEventDispatcher.java:93)
	at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:457)
	at com.atlassian.event.internal.AsynchronousAbleEventDispatcher.dispatch(AsynchronousAbleEventDispatcher.java:88)
	at com.atlassian.event.internal.EventPublisherImpl.invokeListeners(EventPublisherImpl.java:203)
	at com.atlassian.event.internal.EventPublisherImpl.publish(EventPublisherImpl.java:114)
	at com.atlassian.confluence.event.TimingEventPublisher.publish(TimingEventPublisher.java:64)
	at com.atlassian.confluence.pages.DefaultCommentManager.publishRemoveEvent(DefaultCommentManager.java:224)
	at com.atlassian.confluence.core.DefaultContentEntityManager.removeContentEntityInternal(DefaultContentEntityManager.java:222)
	at com.atlassian.confluence.core.DefaultContentEntityManager.removeContentEntity(DefaultContentEntityManager.java:253)
	at com.atlassian.confluence.pages.DefaultCommentManager.removeCommentFromObject(DefaultCommentManager.java:155)
	at com.atlassian.confluence.pages.DefaultCommentManager.removeCommentFromPage(DefaultCommentManager.java:144)
(...)
	at com.sun.proxy.$Proxy138.removeCommentFromPage(Unknown Source)
	at com.atlassian.confluence.content.service.comment.DeleteCommentCommandImpl.executeInternal(DeleteCommentCommandImpl.java:37)
	at com.atlassian.confluence.core.service.AbstractServiceCommand$ServiceCommandState$2.execute(AbstractServiceCommand.java:148)
	at com.atlassian.confluence.core.service.AbstractServiceCommand$ServiceCommandState$6.execute(AbstractServiceCommand.java:286)
	at com.atlassian.confluence.core.service.AbstractServiceCommand.execute(AbstractServiceCommand.java:60)
(...)
	at com.sun.proxy.$Proxy2796.execute(Unknown Source)
	at com.atlassian.confluence.api.impl.service.content.ContentTrashServiceImpl.execute(ContentTrashServiceImpl.java:367)
	at com.atlassian.confluence.api.impl.service.content.ContentTrashServiceImpl.purge(ContentTrashServiceImpl.java:138)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
(...)
	at com.sun.proxy.$Proxy175.purge(Unknown Source)
	at com.atlassian.confluence.api.impl.service.content.ContentServiceImpl.delete(ContentServiceImpl.java:191)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
(...)
	at com.sun.proxy.$Proxy1588.delete(Unknown Source)
	at com.atlassian.confluence.plugins.restapi.resources.ContentResource.delete(ContentResource.java:673)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
(...)

      Notes

      The 2,000 watchers might be an exaggerated scenario, but it is used to show that something is wrong and is causing a bad UI experience to the Confluence user.
      This issue is caused because Confluence is processing notifications within the same thread as the one executing UI operations.
      Adding and deleting a comment to a page should be decoupled from the notifications tasks, meaning that any task related to notifications should be processed by a background thread.

      Below is the result of a comparison on how long it takes to complete each action depending on the number of watchers in a page.

      # of watchers Create comment Delete comment
      0 254ms 1,309ms
      100 1,230ms 4,301ms
      500 6,866ms 18,552ms
      1,000 14,216ms 36,892ms
      2,000 52,487ms 78,998ms

      Workaround

      Tuning the cache may help decreasing the time taken on each related operation, but won't remove the problem.

      Attachments

        Issue Links

          relates to

          Bug - A problem which impairs or prevents the functions of the product. CONFSERVER-29164 Permission checks for Notifications slows down page operations

          • Medium - Medium priority issues
          • Gathering Impact
          mentioned in

          Page Loading...

          Activity

            People

              Unassigned Unassigned
              tmasutti Thiago Masutti
              Votes:
              2 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated: