AuthorizationException caused by ConflictingInsertionException

#1

We are experiencing problems causing irregularly user-facing errors. Mostly the user’s menu will not load completely or a macro will fail because of this. Unfortunately, I am not aware how to reproduce this problem consistently but within the last 48 hours less than five regular users caused this error to happen 183 times. The distribution looks interesting as if something is blocking the security cache in the background sometimes.

image

Does anyone have any hint on how to solve this? We are running XWiki 11.6 docker.

org.xwiki.security.authorization.AuthorizationException: Failed to load the cache in 5 attempts. Giving up. when checking  access to [xwiki:[redacted].WebHome] for user [xwiki:XWiki.[redacted]]
at org.xwiki.security.authorization.cache.internal.DefaultSecurityCacheLoader.load(DefaultSecurityCacheLoader.java:168)
at org.xwiki.security.authorization.DefaultAuthorizationManager.getAccess(DefaultAuthorizationManager.java:209)
at org.xwiki.security.authorization.DefaultAuthorizationManager.evaluateSecurityAccess(DefaultAuthorizationManager.java:159)
at org.xwiki.security.authorization.DefaultAuthorizationManager.hasSecurityAccess(DefaultAuthorizationManager.java:152)
at org.xwiki.security.authorization.DefaultAuthorizationManager.hasAccess(DefaultAuthorizationManager.java:109)
at org.xwiki.query.solr.internal.SolrQueryExecutor.isAllowed(SolrQueryExecutor.java:273)
at org.xwiki.query.solr.internal.SolrQueryExecutor.filterResponse(SolrQueryExecutor.java:244)
at org.xwiki.query.solr.internal.SolrQueryExecutor.execute(SolrQueryExecutor.java:146)
at org.xwiki.query.internal.DefaultQueryExecutorManager.execute(DefaultQueryExecutorManager.java:72)
at org.xwiki.query.internal.SecureQueryExecutorManager.execute(SecureQueryExecutorManager.java:67)
at org.xwiki.query.internal.DefaultQuery.execute(DefaultQuery.java:306)
at org.xwiki.query.internal.ScriptQuery.execute(ScriptQuery.java:252)
at jdk.internal.reflect.GeneratedMethodAccessor613.invoke()
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:566)
at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.doInvoke(UberspectImpl.java:395)
at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.invoke(UberspectImpl.java:384)
at org.apache.velocity.runtime.parser.node.ASTMethod.execute(ASTMethod.java:173)
at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:280)
at org.apache.velocity.runtime.parser.node.ASTReference.value(ASTReference.java:567)
at org.apache.velocity.runtime.parser.node.ASTExpression.value(ASTExpression.java:71)
at org.apache.velocity.runtime.parser.node.ASTSetDirective.render(ASTSetDirective.java:142)
at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)
at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluateInternal(DefaultVelocityEngine.java:259)
at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluate(DefaultVelocityEngine.java:222)
at com.xpn.xwiki.render.DefaultVelocityManager.evaluate(DefaultVelocityManager.java:358)
at org.xwiki.rendering.internal.macro.velocity.VelocityMacro.evaluateString(VelocityMacro.java:131)
at org.xwiki.rendering.internal.macro.velocity.VelocityMacro.evaluateString(VelocityMacro.java:52)
at org.xwiki.rendering.macro.script.AbstractScriptMacro.evaluateBlock(AbstractScriptMacro.java:286)
at org.xwiki.rendering.macro.script.AbstractScriptMacro.execute(AbstractScriptMacro.java:182)
at org.xwiki.rendering.macro.script.AbstractScriptMacro.execute(AbstractScriptMacro.java:58)
at org.xwiki.rendering.internal.transformation.macro.MacroTransformation.transform(MacroTransformation.java:297)
at org.xwiki.rendering.internal.transformation.DefaultRenderingContext.transformInContext(DefaultRenderingContext.java:183)
at org.xwiki.rendering.async.internal.block.AbstractBlockAsyncRenderer.transform(AbstractBlockAsyncRenderer.java:59)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRenderer.tranform(DefaultBlockAsyncRenderer.java:155)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRenderer.render(DefaultBlockAsyncRenderer.java:123)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRenderer.render(DefaultBlockAsyncRenderer.java:51)
at org.xwiki.uiextension.internal.WikiUIExtension.render(WikiUIExtension.java:179)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRendererExecutor$DecoratorWrapper.render(DefaultBlockAsyncRendererExecutor.java:66)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRendererExecutor$DecoratorWrapper.render(DefaultBlockAsyncRendererExecutor.java:48)
at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.lambda$syncRender$0(DefaultAsyncRendererExecutor.java:257)
at com.xpn.xwiki.internal.security.authorization.DefaultAuthorExecutor.call(DefaultAuthorExecutor.java:98)
at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.syncRender(DefaultAsyncRendererExecutor.java:257)
at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.render(DefaultAsyncRendererExecutor.java:240)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRendererExecutor.execute(DefaultBlockAsyncRendererExecutor.java:119)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRendererExecutor.execute(DefaultBlockAsyncRendererExecutor.java:107)
at org.xwiki.uiextension.internal.AbstractWikiUIExtension.execute(AbstractWikiUIExtension.java:112)
at jdk.internal.reflect.GeneratedMethodAccessor285.invoke()
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:566)
at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.doInvoke(UberspectImpl.java:395)
at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.invoke(UberspectImpl.java:384)
at org.apache.velocity.runtime.parser.node.ASTMethod.execute(ASTMethod.java:173)
at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:280)
at org.apache.velocity.runtime.parser.node.ASTReference.value(ASTReference.java:567)
at org.apache.velocity.runtime.parser.node.ASTMethod.execute(ASTMethod.java:151)
at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:280)
at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:369)
at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:87)
at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)
at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluateInternal(DefaultVelocityEngine.java:259)
at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluate(DefaultVelocityEngine.java:222)
at com.xpn.xwiki.render.DefaultVelocityManager.evaluate(DefaultVelocityManager.java:358)
at org.xwiki.rendering.internal.macro.velocity.VelocityMacro.evaluateString(VelocityMacro.java:131)
at org.xwiki.rendering.internal.macro.velocity.VelocityMacro.evaluateString(VelocityMacro.java:52)
at org.xwiki.rendering.macro.script.AbstractScriptMacro.evaluateBlock(AbstractScriptMacro.java:286)
at org.xwiki.rendering.macro.script.AbstractScriptMacro.execute(AbstractScriptMacro.java:182)
at org.xwiki.rendering.macro.script.AbstractScriptMacro.execute(AbstractScriptMacro.java:58)
at org.xwiki.rendering.internal.transformation.macro.MacroTransformation.transform(MacroTransformation.java:297)
at org.xwiki.rendering.internal.transformation.DefaultRenderingContext.transformInContext(DefaultRenderingContext.java:183)
at org.xwiki.rendering.async.internal.block.AbstractBlockAsyncRenderer.transform(AbstractBlockAsyncRenderer.java:59)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRenderer.tranform(DefaultBlockAsyncRenderer.java:155)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRenderer.render(DefaultBlockAsyncRenderer.java:123)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRenderer.render(DefaultBlockAsyncRenderer.java:51)
at org.xwiki.uiextension.internal.WikiUIExtension.render(WikiUIExtension.java:179)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRendererExecutor$DecoratorWrapper.render(DefaultBlockAsyncRendererExecutor.java:66)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRendererExecutor$DecoratorWrapper.render(DefaultBlockAsyncRendererExecutor.java:48)
at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.lambda$syncRender$0(DefaultAsyncRendererExecutor.java:257)
at com.xpn.xwiki.internal.security.authorization.DefaultAuthorExecutor.call(DefaultAuthorExecutor.java:98)
at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.syncRender(DefaultAsyncRendererExecutor.java:257)
at org.xwiki.rendering.async.internal.DefaultAsyncRendererExecutor.render(DefaultAsyncRendererExecutor.java:240)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRendererExecutor.execute(DefaultBlockAsyncRendererExecutor.java:119)
at org.xwiki.rendering.async.internal.block.DefaultBlockAsyncRendererExecutor.execute(DefaultBlockAsyncRendererExecutor.java:107)
at org.xwiki.uiextension.internal.AbstractWikiUIExtension.execute(AbstractWikiUIExtension.java:112)
at jdk.internal.reflect.GeneratedMethodAccessor285.invoke()
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:566)
at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.doInvoke(UberspectImpl.java:395)
at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.invoke(UberspectImpl.java:384)
at org.apache.velocity.runtime.parser.node.ASTMethod.execute(ASTMethod.java:173)
at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:280)
at org.apache.velocity.runtime.parser.node.ASTReference.value(ASTReference.java:567)
at org.apache.velocity.runtime.parser.node.ASTMethod.execute(ASTMethod.java:151)
at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:280)
at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:369)
at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
at org.apache.velocity.runtime.directive.Foreach.render(Foreach.java:420)
at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)
at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:216)
at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:311)
at org.apache.velocity.runtime.directive.RuntimeMacro.render(RuntimeMacro.java:230)
at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:207)
at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)
at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:106)
at org.apache.velocity.runtime.parser.node.ASTBlock.render(ASTBlock.java:72)
at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)
at org.apache.velocity.runtime.parser.node.ASTIfStatement.render(ASTIfStatement.java:106)
at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342)
at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluateInternal(DefaultVelocityEngine.java:259)
at org.xwiki.velocity.internal.DefaultVelocityEngine.evaluate(DefaultVelocityEngine.java:222)
at com.xpn.xwiki.render.DefaultVelocityManager.evaluate(DefaultVelocityManager.java:358)
at com.xpn.xwiki.internal.template.InternalTemplateManager.evaluateContent(InternalTemplateManager.java:884)
at com.xpn.xwiki.internal.template.InternalTemplateManager.render(InternalTemplateManager.java:755)
at com.xpn.xwiki.internal.template.InternalTemplateManager.lambda$renderFromSkin$0(InternalTemplateManager.java:730)
at com.xpn.xwiki.internal.security.authorization.DefaultAuthorExecutor.call(DefaultAuthorExecutor.java:98)
at com.xpn.xwiki.internal.template.InternalTemplateManager.renderFromSkin(InternalTemplateManager.java:729)
at com.xpn.xwiki.internal.template.InternalTemplateManager.renderFromSkin(InternalTemplateManager.java:708)
at com.xpn.xwiki.internal.template.InternalTemplateManager.render(InternalTemplateManager.java:694)
at com.xpn.xwiki.internal.template.DefaultTemplateManager.render(DefaultTemplateManager.java:78)
at com.xpn.xwiki.XWiki.evaluateTemplate(XWiki.java:2479)
at com.xpn.xwiki.web.Utils.parseTemplate(Utils.java:179)
at com.xpn.xwiki.web.Utils.parseTemplate(Utils.java:88)
at com.xpn.xwiki.web.XWikiAction.execute(XWikiAction.java:508)
at com.xpn.xwiki.web.XWikiAction.execute(XWikiAction.java:215)
at org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:425)
at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:228)
at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1913)
at org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:449)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:634)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.xpn.xwiki.web.ActionFilter.doFilter(ActionFilter.java:112)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.xwiki.wysiwyg.filter.ConversionFilter.doFilter(ConversionFilter.java:109)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.xwiki.container.servlet.filters.internal.SetHTTPHeaderFilter.doFilter(SetHTTPHeaderFilter.java:63)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.xwiki.container.servlet.filters.internal.SavedRequestRestorerFilter.doFilter(SavedRequestRestorerFilter.java:208)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.xwiki.container.servlet.filters.internal.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:111)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.xwiki.resource.servlet.RoutingFilter.doFilter(RoutingFilter.java:132)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:660)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:679)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:798)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:808)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:834)

Caused by: org.xwiki.security.authorization.cache.ConflictingInsertionException
at org.xwiki.security.authorization.cache.internal.DefaultSecurityCache.addEntry(DefaultSecurityCache.java:642)
at org.xwiki.security.authorization.cache.internal.DefaultSecurityCache.internalAdd(DefaultSecurityCache.java:760)
at org.xwiki.security.authorization.cache.internal.DefaultSecurityCache.add(DefaultSecurityCache.java:736)
at org.xwiki.security.authorization.cache.internal.DefaultSecurityCacheLoader.loadAccessEntries(DefaultSecurityCacheLoader.java:231)
at org.xwiki.security.authorization.cache.internal.DefaultSecurityCacheLoader.loadRequiredEntries(DefaultSecurityCacheLoader.java:197)
at org.xwiki.security.authorization.cache.internal.DefaultSecurityCacheLoader.load(DefaultSecurityCacheLoader.java:150)
... 170 more
0 Likes

#2

Hello @zonradkuse, This sounds a bit tricky… I have no specific investigation idea about this, just ccing @dgervalle in case he has one (and time) :slight_smile:

Cheers

0 Likes

#3

This is definitely an unexpected issue that could only happen in very loaded environment when thread concurrency is an issue or the number of users/groups is too high for the security cache size. I would suggest two potential ways to improve the situation:

  • increase the resources allocated to the container
  • increase the size of the security cache (Infinispan cache with id platform.security.authorization.cache)

I hope these suggestions will help.
Regards,

0 Likes

#4

Hi @dgervalle, @slauriere,

Thanks for the quick replies and the hints! The JVM is allowed to use up to 1.6G and according to glowroot the MemoryUsage is around 900MB.

I am going to try to increase the inifinispan cache. Interestingly, the errors seem to decrease over time. In other words we didn’t experience such a massive spike in cache errors again. Throughout a day we might experience 5 to no exceptions of this kind. However, I haven’t restarted XWiki since.

I’ll keep you updated. Have a good weekend.

Best
Johannes

0 Likes