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

When inserting a macro into a page, macro browser errors with "Failed to get macro details" because of race condition in gadgets ehcache acquiring

      NOTE: This bug report is for Confluence Server. Using Confluence Cloud? See the corresponding bug report.

      Summary

      Occasionally users will attempt to insert a macro into Confluence and receive an error, Failed to get macro details

      Environment

      • Confluence 5.9.1-OD-2015.40.1-0001

      Steps to Reproduce

      1. Unknown what triggers, but may be a caching issue.
      2. On an affected instance, go to edit a page in Confluence, type a curly bracket, and instead of the macro browser loading, you receive the error above.

      Expected Results

      Generally typing curly bracket will load the macro browser

      Actual Results

      From clog when loading the macro browser:

      2015-10-13 10:33:42.754518500 2015-10-13 10:33:42,721 ERROR [ajp-bio-127.0.0.101-8009-exec-2306] [atlassian.confluence.servlet.ConfluenceServletDispatcher] sendError Could not execute action
      2015-10-13 10:33:42.754520500  -- referer: https://*/wiki/display/KEY/Page+Name | url: /wiki/plugins/macrobrowser/browse-macros.action | username: johnsmith
      2015-10-13 10:33:42.754521500 com.atlassian.cache.CacheException: java.lang.NullPointerException
      2015-10-13 10:33:42.754521500 	at com.atlassian.cache.ehcache.DelegatingCache.get(DelegatingCache.java:101)
      2015-10-13 10:33:42.754542500 	at com.atlassian.confluence.cache.ehcache.DefaultConfluenceEhCache.get(DefaultConfluenceEhCache.java:46)
      2015-10-13 10:33:42.754543500 	at com.atlassian.confluence.cache.ConfluenceMonitoringCache.get(ConfluenceMonitoringCache.java:49)
      2015-10-13 10:33:42.754543500 	at com.atlassian.confluence.plugins.gadgets.metadata.CachingGadgetsMacroMetadataProvider.getData(CachingGadgetsMacroMetadataProvider.java:127)
      2015-10-13 10:33:42.754546500 	at com.atlassian.confluence.plugins.gadgets.metadata.CachingGadgetsMacroMetadataProvider.getSummaries(CachingGadgetsMacroMetadataProvider.java:147)
      2015-10-13 10:33:42.754548500 	at com.atlassian.confluence.macro.browser.DefaultMacroMetadataManager.buildMacroSummaries(DefaultMacroMetadataManager.java:173)
      2015-10-13 10:33:42.754553500 	at com.atlassian.confluence.macro.browser.DefaultMacroMetadataManager.getAllMacroSummaries(DefaultMacroMetadataManager.java:90)
      2015-10-13 10:33:42.754553500 	at com.atlassian.confluence.macro.browser.DefaultMacroBrowserManager.getMacroSummaries(DefaultMacroBrowserManager.java:61)
      2015-10-13 10:33:42.754554500 	at com.atlassian.confluence.macro.browser.actions.BrowseMacrosAction.getSummaries(BrowseMacrosAction.java:85)
      2015-10-13 10:33:42.754557500 	at com.atlassian.confluence.macro.browser.actions.BrowseMacrosAction.execute(BrowseMacrosAction.java:47)
      2015-10-13 10:33:42.754557500 	at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:168)
      2015-10-13 10:33:42.754558500 	at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:35)
      2015-10-13 10:33:42.754559500 	at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:165)
      2015-10-13 10:33:42.754561500 	at com.atlassian.confluence.core.ConfluenceWorkflowInterceptor.intercept(ConfluenceWorkflowInterceptor.java:65)
      2015-10-13 10:33:42.754562500 	at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:165)
      2015-10-13 10:33:42.754563500 	at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:35)
      2015-10-13 10:33:42.754567500 	at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:165)
      2015-10-13 10:33:42.754567500 	at com.atlassian.xwork.interceptors.XsrfTokenInterceptor.intercept(XsrfTokenInterceptor.java:100)
      
      ...
      
      2015-10-13 10:33:42.755160500 	at com.atlassian.confluence.plugins.gadgets.metadata.GadgetCacheFlusher.getGadgetsCaches(GadgetCacheFlusher.java:163)
      2015-10-13 10:33:42.755161500 	at com.atlassian.confluence.plugins.gadgets.metadata.GadgetCacheFlusher.performSelectiveGadgetsCacheFlush(GadgetCacheFlusher.java:109)
      2015-10-13 10:33:42.755164500 	at com.atlassian.confluence.plugins.gadgets.metadata.GadgetCacheFlusher.requestGadgetsCacheFlush(GadgetCacheFlusher.java:95)
      2015-10-13 10:33:42.755165500 	at com.atlassian.confluence.plugins.gadgets.metadata.MetadataCacheLoader.load(MetadataCacheLoader.java:46)
      2015-10-13 10:33:42.755166500 	at com.atlassian.confluence.plugins.gadgets.metadata.MetadataCacheLoader.load(MetadataCacheLoader.java:22)
      2015-10-13 10:33:42.755171500 	at com.atlassian.cache.ehcache.LoadingCache.getFromLoader(LoadingCache.java:145)
      2015-10-13 10:33:42.755172500 	at com.atlassian.cache.ehcache.LoadingCache.loadValueAndReleaseLock(LoadingCache.java:100)
      2015-10-13 10:33:42.755172500 	at com.atlassian.cache.ehcache.LoadingCache.get(LoadingCache.java:76)
      2015-10-13 10:33:42.755173500 	at com.atlassian.cache.ehcache.DelegatingCache.get(DelegatingCache.java:96)
      2015-10-13 10:33:42.755175500 	... 339 more
      2015-10-13 10:33:42.756931500 2015-10-13 10:33:42,755 INFO [ajp-bio-127.0.0.101-8009-exec-2306] [atlassian.confluence.status.SystemErrorInformationLogger] writeToLog
      2015-10-13 10:33:42.756933500 Request Unique ID : 4e51a8ee-a2dc-470e-9f59-6af7e57e4fa9
      2015-10-13 10:33:42.756933500 --------------------------
      2015-10-13 10:33:42.756933500 JVM Stats
      2015-10-13 10:33:42.756934500 --------------------------
      2015-10-13 10:33:42.756934500 usedMemory = 652840544
      2015-10-13 10:33:42.756934500 usedMemoryInMegabytes = 622
      2015-10-13 10:33:42.756934500 availableHeap = 408973728
      2015-10-13 10:33:42.756945500 freeMemoryInMegabytes = 167
      2015-10-13 10:33:42.756946500 allocatedHeap = 828534784
      2015-10-13 10:33:42.756946500 freeAllocatedHeap = 175694240
      2015-10-13 10:33:42.756946500 totalMemory = 828534784
      2015-10-13 10:33:42.756947500 totalMemoryInMegabytes = 790
      2015-10-13 10:33:42.756947500 availablePermGen = 0
      2015-10-13 10:33:42.756947500 maxPermGen = -1
      2015-10-13 10:33:42.756948500 maxHeap = 1061814272
      2015-10-13 10:33:42.756948500 usedHeap = 652840544
      2015-10-13 10:33:42.756948500 freeMemory = 175694240
      2015-10-13 10:33:42.756950500 usedPermGen = -1
      2015-10-13 10:33:42.756950500 --------------------------
      2015-10-13 10:33:42.756951500 Request Information
      2015-10-13 10:33:42.756951500 --------------------------
      2015-10-13 10:33:42.756951500 URL: https://*/wiki/500page.jsp
      2015-10-13 10:33:42.756952500 Scheme: https
      2015-10-13 10:33:42.756952500 Server: *
      2015-10-13 10:33:42.756952500 Port: 443
      2015-10-13 10:33:42.756952500 URI: /wiki/500page.jsp
      2015-10-13 10:33:42.756953500 Context Path: /wiki
      2015-10-13 10:33:42.756955500 Servlet Path: /500page.jsp
      2015-10-13 10:33:42.756955500 Path Info: null
      2015-10-13 10:33:42.756955500 Query String: detailed=false&macroMetadataClientCacheKey=1444607378198
      2015-10-13 10:33:42.756956500 --------------------------
      2015-10-13 10:33:42.756956500 Attributes
      2015-10-13 10:33:42.756956500 --------------------------
      2015-10-13 10:33:42.756957500 javax.servlet.forward.request_uri: /wiki/plugins/macrobrowser/browse-macros.action
      2015-10-13 10:33:42.756961500 javax.servlet.forward.context_path: /wiki
      2015-10-13 10:33:42.756961500 javax.servlet.forward.servlet_path: /plugins/macrobrowser/browse-macros.action
      2015-10-13 10:33:42.756962500 javax.servlet.forward.query_string: detailed=false&macroMetadataClientCacheKey=1444607378198
      2015-10-13 10:33:42.756962500 javax.servlet.error.status_code: 500
      2015-10-13 10:33:42.756963500 com.opensymphony.sitemesh.APPLIED_ONCE: true
      2015-10-13 10:33:42.756965500 __cleanup_recursion_counter: 0
      2015-10-13 10:33:42.756965500 com.atlassian.confluence.web.filter.validateparam.RequestParamValidationFilter_already_filtered: true
      2015-10-13 10:33:42.756966500 atlassian.core.seraph.original.url: /500page.jsp?detailed=false&macroMetadataClientCacheKey=1444607378198
      2015-10-13 10:33:42.756967500 com.atlassian.labs.botkiller.BotKillerFilter: true
      2015-10-13 10:33:42.756967500 com.atlassian.gzipfilter.GzipFilter_already_filtered: true
      2015-10-13 10:33:42.756969500 Confluence-Request-Time: 1444725222489
      2015-10-13 10:33:42.756969500 com.atlassian.confluence.web.ConfluenceJohnsonFilter_already_filtered: true
      2015-10-13 10:33:42.756970500 com.atlassian.seraph.auth.LoginReason: OK
      2015-10-13 10:33:42.756970500 com.atlassian.plugins.landlord.servlet.TenantHeaderFilter_already_filtered: true
      2015-10-13 10:33:42.756971500 webwork.valueStack: com.opensymphony.xwork.util.OgnlValueStack@12d9680
      2015-10-13 10:33:42.756973500 confluence.themecontext: com.atlassian.confluence.themes.ThemeContext@1f4704d
      2015-10-13 10:33:42.756978500 javax.servlet.error.message:
      2015-10-13 10:33:42.756979500 javax.servlet.error.servlet_name: action
      2015-10-13 10:33:42.756979500 com.atlassian.confluence.security.websudo.MessagesDecoratorFilter__already_filtered__: true
      2015-10-13 10:33:42.756980500 com.opensymphony.sitemesh.USINGSTREAM: false
      2015-10-13 10:33:42.756980500 loginfilter.already.filtered: true
      2015-10-13 10:33:42.756981500 javax.servlet.jsp.jspException: com.atlassian.cache.CacheException: java.lang.NullPointerException
      2015-10-13 10:33:42.756983500 javax.servlet.error.request_uri: /wiki/plugins/macrobrowser/browse-macros.action
      2015-10-13 10:33:42.756984500 com.atlassian.core.filters.HeaderSanitisingFilter_already_filtered: true
      2015-10-13 10:33:42.756985500 com.atlassian.prettyurls.filter.PrettyUrlsSiteMeshFixupFilter: true
      2015-10-13 10:33:42.756985500 javax.servlet.error.exception: com.atlassian.cache.CacheException: java.lang.NullPointerException
      2015-10-13 10:33:42.756987500 os_securityfilter_already_filtered: true
      2015-10-13 10:33:42.756988500 com.atlassian.prettyurls.filter.PrettyUrlsSiteMeshFilter: true
      2015-10-13 10:33:42.756988500 --------------------------
      2015-10-13 10:33:42.756989500 Parameters
      2015-10-13 10:33:42.756989500 --------------------------
      2015-10-13 10:33:42.756989500 macroMetadataClientCacheKey : 1444607378198
      2015-10-13 10:33:42.756990500 detailed : false
      2015-10-13 10:33:42.756996500 caused by: com.atlassian.cache.CacheException: java.lang.NullPointerException
      2015-10-13 10:33:42.756996500 at com.atlassian.cache.ehcache.DelegatingCache.get(DelegatingCache.java:101)
      2015-10-13 10:33:42.757001500 caused by: java.lang.NullPointerException
      2015-10-13 10:33:42.757001500 at com.atlassian.confluence.cache.ehcache.EhCacheManager.wrapCache(EhCacheManager.java:176)
      2015-10-13 10:33:42.757002500
      2015-10-13 10:33:52.644892500 2015-10-13 10:33:52,624 ERROR [ajp-bio-127.0.0.101-8009-exec-2309] [atlassian.confluence.servlet.ConfluenceServletDispatcher] sendError Could not execute action
      2015-10-13 10:33:52.644894500  -- referer: https://*/wiki/pages/createpage.action?spaceKey=KEY&fromPageId=96764471&src=quick-create | url: /wiki/plugins/macrobrowser/browse-macros.action | userName: johnsmith
      2015-10-13 10:33:52.644895500 com.atlassian.cache.CacheException: java.lang.NullPointerException
      2015-10-13 10:33:52.644896500 	at com.atlassian.cache.ehcache.DelegatingCache.get(DelegatingCache.java:101)
      2015-10-13 10:33:52.644906500 	at com.atlassian.confluence.cache.ehcache.DefaultConfluenceEhCache.get(DefaultConfluenceEhCache.java:46)
      2015-10-13 10:33:52.644906500 	at com.atlassian.confluence.cache.ConfluenceMonitoringCache.get(ConfluenceMonitoringCache.java:49)
      2015-10-13 10:33:52.644907500 	at com.atlassian.confluence.plugins.gadgets.metadata.CachingGadgetsMacroMetadataProvider.getData(CachingGadgetsMacroMetadataProvider.java:127)
      2015-10-13 10:33:52.644909500 	at com.atlassian.confluence.plugins.gadgets.metadata.CachingGadgetsMacroMetadataProvider.getSummaries(CachingGadgetsMacroMetadataProvider.java:147)
      2015-10-13 10:33:52.644910500 	at com.atlassian.confluence.macro.browser.DefaultMacroMetadataManager.buildMacroSummaries(DefaultMacroMetadataManager.java:173)
      2015-10-13 10:33:52.644914500 	at com.atlassian.confluence.macro.browser.DefaultMacroMetadataManager.getAllMacroSummaries(DefaultMacroMetadataManager.java:90)
      2015-10-13 10:33:52.644914500 	at com.atlassian.confluence.macro.browser.DefaultMacroBrowserManager.getMacroSummaries(DefaultMacroBrowserManager.java:61)
      2015-10-13 10:33:52.644915500 	at com.atlassian.confluence.macro.browser.actions.BrowseMacrosAction.getSummaries(BrowseMacrosAction.java:85)
      2015-10-13 10:33:52.644917500 	at com.atlassian.confluence.macro.browser.actions.BrowseMacrosAction.execute(BrowseMacrosAction.java:47)
      2015-10-13 10:33:52.644917500 	at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:168)
      2015-10-13 10:33:52.644918500 	at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:35)
      2015-10-13 10:33:52.644918500 	at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:165)
      2015-10-13 10:33:52.644920500 	at com.atlassian.confluence.core.ConfluenceWorkflowInterceptor.intercept(ConfluenceWorkflowInterceptor.java:65)
      2015-10-13 10:33:52.644920500 	at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:165)
      2015-10-13 10:33:52.644923500 	at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:35)
      2015-10-13 10:33:52.644924500 	at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:165)
      2015-10-13 10:33:52.644924500 	at com.atlassian.xwork.interceptors.XsrfTokenInterceptor.intercept(XsrfTokenInterceptor.java:100)
      2015-10-13 10:33:52.644925500 	at com.atlassian.confluence.xwork.ConfluenceXsrfTokenInterceptor.intercept(ConfluenceXsrfTokenInterceptor.java:26)
      

      Workaround 1

      1. Disable the "Gadget Plugin" and the "Gadget Plugin SPI". This will allow the macro browser to load, minus gadgets
      2. Re-enable each plugin

      Workaround 2

      1. Restart Confluence

      Workaround 3

      1. If you are using Copy Page Tree, downgrading Copy Page Tree plugin from 2.5.X to version 2.4.2.
      2. You may follow the knowledge base below to downgrade Confluence
      3. Download version 2.4.2 from the link below.

      Dev Notes

        1. confluence_macro_problem.log
          37 kB
        2. confluence-macro-browser-problem.txt
          41 kB
        3. confluence-macro-bug.png
          confluence-macro-bug.png
          12 kB
        4. macro-expansion-bug.log
          50 kB
        5. macro-expansion-bug2.log
          719 kB
        6. Screen Shot 2015-09-15 at 1.50.46 pm.png
          Screen Shot 2015-09-15 at 1.50.46 pm.png
          38 kB

            [CONFSERVER-39555] When inserting a macro into a page, macro browser errors with "Failed to get macro details" because of race condition in gadgets ehcache acquiring

            Feng Xu (Inactive) added a comment - - edited

            Dear all,

            This issue has been resolved in 5.10, however, we have noticed there are many support tickets being raised against this issue since 03/2017, suggesting there might have been a regression. After reviewing the logs from these tickets, we have the following findings,

            Based on the investigation result, we will close this ticket. If your Confluence has Copy Page Tree installed, we would suggest to upgrade your Confluence instance to a version having the fix for https://jira.atlassian.com/browse/CONFSERVER-52551,  alternatively, uninstall or downgrade the Copy Page Tree plugin.

            Feel free to leave your comments if you have any concerns.

            Regards,

            Feng Xu

            Confluence Server

             

            Feng Xu (Inactive) added a comment - - edited Dear all, This issue has been resolved in 5.10, however, we have noticed there are many support tickets being raised against this issue since 03/2017, suggesting there might have been a regression. After reviewing the logs from these tickets, we have the following findings, most of the impacted customers have  Copy Page Tree plugin 2.5.X installed, which could trigger the issue - https://jira.atlassian.com/browse/CONFSERVER-52551  that has the similar symptom and has been resolved in 6.2.4 and 6.3.2. there are two Confluence instances running with 6.3.2 or later version, which have a different cause that the request times out when connecting to the gadget URL. To deal with the gadget related error, we have created a new ticket - https://jira.atlassian.com/browse/CONFSERVER-53531  - to track it Based on the investigation result, we will close this ticket. If your Confluence has Copy Page Tree installed, we would suggest to upgrade your Confluence instance to a version having the fix for https://jira.atlassian.com/browse/CONFSERVER-52551 ,  alternatively, uninstall or downgrade the Copy Page Tree plugin. Feel free to leave your comments if you have any concerns. Regards, Feng Xu Confluence Server  

            I am also having this issue!
            Running confluence 6.3.3. Fresh installed, and running into the same problem. Only helps to disable the "Gadget Plugin" and the "Gadget Plugin SPI".

            Could you please provide support on this? And/or reopen the issue?

            Thanks

            Eduardo Puente added a comment - I am also having this issue! Running confluence 6.3.3. Fresh installed, and running into the same problem. Only helps to disable the "Gadget Plugin" and the "Gadget Plugin SPI". Could you please provide support on this? And/or reopen the issue? Thanks

            Cory Johnson added a comment - - edited

            I have seen this issue with Confluence 6 when trying to insert new Macro. I am still waiting for some kind of patch. Is anyone else seeing this issue in Confluence 6?

            Cory Johnson added a comment - - edited I have seen this issue with Confluence 6 when trying to insert new Macro. I am still waiting for some kind of patch. Is anyone else seeing this issue in Confluence 6?

            Roman Joss added a comment -

            Hello Robert

            Thanks for your workaraound. I have deinstalled the plugin 'Copy Page Tree', Version 2.5.2 and our macro browser works again with all jira-macros. Every jira-macro can now be inserted and edited. I wrote to Artemis for this case, as i cannot install the Version 2.4.2 of the plugin into Confluence 6.1.1.

            Currently our Major-Problem is solved. Now we wait for a repaired Version from Copy Page Tree.
            Many thanks and regards,
            Roman

            Roman Joss added a comment - Hello Robert Thanks for your workaraound. I have deinstalled the plugin 'Copy Page Tree', Version 2.5.2 and our macro browser works again with all jira-macros. Every jira-macro can now be inserted and edited. I wrote to Artemis for this case, as i cannot install the Version 2.4.2 of the plugin into Confluence 6.1.1. Currently our Major-Problem is solved. Now we wait for a repaired Version from Copy Page Tree. Many thanks and regards, Roman

            it seems partly related, downgrading that plugin as mentionned worked, then I tried to add back my gadget feed and it broke exactly like before, only fix (removing gadget feed did not work) was to disable the gadget metadata browser module again

            adrien rochereau added a comment - it seems partly related, downgrading that plugin as mentionned worked, then I tried to add back my gadget feed and it broke exactly like before, only fix (removing gadget feed did not work) was to disable the gadget metadata browser module again

            Robert Chang added a comment - - edited

            All,

            We've found that the vast majority of clients that have reported this issue also have Copy Page Plugin 2.5.0, 2.5.2 or 2.5.3 installed. Some customers have found that by when uninstalling those versions and downgrading to 2.4.2 of the plugin (which can be downloaded here), the issue is resolved.

            If you've tried this workaround, please add a comment here on whether it was successful for you.

            Robert Chang added a comment - - edited All, We've found that the vast majority of clients that have reported this issue also have Copy Page Plugin 2.5.0, 2.5.2 or 2.5.3 installed. Some customers have found that by when uninstalling those versions and downgrading to 2.4.2 of the plugin (which can be downloaded here ), the issue is resolved. If you've tried this workaround, please add a comment here on whether it was successful for you.

            MattS added a comment -

            For 5.9.8 I had to:

            1. Disable the "Gadgets Plugin" and the "Gadgets Plugin SPI".  (Note name spelling change here)
            2. Leave them disabled until we could restart and clear the plugin cache

            MattS added a comment - For 5.9.8 I had to: Disable the "Gadgets Plugin" and the "Gadgets Plugin SPI".  (Note name spelling change here) Leave them disabled until we could restart and clear the plugin cache

            Same issue in 5.9.5, started today after we had been running for a while without this problem

            adrien rochereau added a comment - Same issue in 5.9.5, started today after we had been running for a while without this problem

            Roman Joss added a comment -

            We are affected by this bug in Version 5.9.12. An Update to 5.10.8 did not resolve the issue. On both Versions we had to disable the Gadget Plugin to get the macro-browser work again. In Version 6.1.1, the bug seams to be resolved.

            Roman Joss added a comment - We are affected by this bug in Version 5.9.12. An Update to 5.10.8 did not resolve the issue. On both Versions we had to disable the Gadget Plugin to get the macro-browser work again. In Version 6.1.1, the bug seams to be resolved.

            Real soon, sorry no hard date yet.

            Petro Semeniuk (Inactive) added a comment - Real soon, sorry no hard date yet.

              fxu Feng Xu (Inactive)
              smackie@atlassian.com Shannon S
              Affected customers:
              10 This affects my team
              Watchers:
              50 Start watching this issue

                Created:
                Updated:
                Resolved: