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

    XMLWordPrintable

Details

    Description

      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

      Attachments

        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

        Issue Links

          is caused by

          Bug - A problem which impairs or prevents the functions of the product. CONFSERVER-52551 External Gadgets not working due to error with MacroMetadataProvider

          • High - High priority issues
          • Closed
          relates to

          Bug - A problem which impairs or prevents the functions of the product. CONFCLOUD-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

          • Medium - Medium priority issues
          • Closed
          included in

          [JIRA] CPU-188 Confluence 6.0.0-OD-2016.02.1-0002

          [JIRA] CPU-198 Confluence 6.0.0-OD-2016.02.1-0005

          [JIRA] CPU-212 Confluence 6.0.0-OD-2016.02.1-0006

          mentioned in

          Page Loading...

          Page Loading...

          Page Loading...

          Page Loading...

          Activity

            People

              fxu Feng Xu (Inactive)
              smackie@atlassian.com Shannon S
              Votes:
              10 Vote for this issue
              Watchers:
              50 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: