ObjectLedge

invoking templating.Restart action on active system can lead to a deadlock

Details

  • Type: Bug Bug
  • Status: Resolved Resolved
  • Priority: Major Major
  • Resolution: Fixed/Completed
  • Affects Version/s: 1.0.2
  • Fix Version/s: 1.0.3
  • Component/s: templating
  • Labels:
    None

Description

JStack output showcasing the deadlock:

Found one Java-level deadlock:
=============================
"TP-Processor125":
  waiting to lock monitor 0x00002aac443936c0 (object 0x00002aabd5487e40, a org.apache.velocity.runtime.VelocimacroFactory),
  which is held by "TP-Processor143"
"TP-Processor143":
  waiting to lock monitor 0x00002aac3c8dbed8 (object 0x00002aabd54204c0, a org.apache.velocity.runtime.resource.ResourceManagerImpl),
  which is held by "TP-Processor125"

Java stack information for the threads listed above:
===================================================
"TP-Processor125":
at org.apache.velocity.runtime.VelocimacroFactory.canAddVelocimacro(VelocimacroFactory.java:380)
- waiting to lock <0x00002aabd5487e40> (a org.apache.velocity.runtime.VelocimacroFactory)
at org.apache.velocity.runtime.VelocimacroFactory.addVelocimacro(VelocimacroFactory.java:341)
at org.apache.velocity.runtime.RuntimeInstance.addVelocimacro(RuntimeInstance.java:1281)
at org.apache.velocity.runtime.directive.Macro.processAndRegister(Macro.java:207)
at org.apache.velocity.runtime.parser.Parser.Directive(Parser.java:856)
at org.apache.velocity.runtime.parser.Parser.Statement(Parser.java:320)
at org.apache.velocity.runtime.parser.Parser.process(Parser.java:258)
at org.apache.velocity.runtime.parser.Parser.parse(Parser.java:105)
at org.apache.velocity.runtime.RuntimeInstance.parse(RuntimeInstance.java:1042)
at org.apache.velocity.runtime.RuntimeInstance.parse(RuntimeInstance.java:972)
at org.apache.velocity.Template.process(Template.java:120)
at org.apache.velocity.runtime.resource.ResourceManagerImpl.loadResource(ResourceManagerImpl.java:415)
at org.apache.velocity.runtime.resource.ResourceManagerImpl.getResource(ResourceManagerImpl.java:335)
- locked <0x00002aabd54204c0> (a org.apache.velocity.runtime.resource.ResourceManagerImpl)
at org.apache.velocity.runtime.RuntimeInstance.getTemplate(RuntimeInstance.java:1102)
at org.apache.velocity.runtime.RuntimeInstance.getTemplate(RuntimeInstance.java:1077)
at org.apache.velocity.app.VelocityEngine.getTemplate(VelocityEngine.java:528)
at org.objectledge.templating.velocity.VelocityTemplating.getTemplate(VelocityTemplating.java:270)
at org.objectledge.web.mvc.finders.MVCFinder.findTemplate(MVCFinder.java:236)
at org.objectledge.web.mvc.finders.MVCFinder.getComponentTemplate(MVCFinder.java:139)
at org.objectledge.web.mvc.components.ComponentTool.embed(ComponentTool.java:133)
at org.objectledge.web.mvc.components.ComponentTool.embed(ComponentTool.java:117)
at sun.reflect.GeneratedMethodAccessor29.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.velocity.util.introspection.UberspectImpl$VelMethodImpl.invoke(UberspectImpl.java:295)
at org.apache.velocity.runtime.parser.node.ASTMethod.execute(ASTMethod.java:245)
at org.apache.velocity.runtime.parser.node.ASTReference.execute(ASTReference.java:203)
at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:294)
at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:318)
at org.apache.velocity.runtime.directive.VelocimacroProxy.render(VelocimacroProxy.java:194)
at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:170)
at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:318)
at org.apache.velocity.Template.merge(Template.java:254)
at org.objectledge.templating.velocity.VelocityTemplating.merge(VelocityTemplating.java:331)
at org.objectledge.templating.velocity.VelocityTemplate.merge(VelocityTemplate.java:48)
at org.objectledge.web.mvc.builders.AbstractBuilder.build(AbstractBuilder.java:88)
at net.cyklotron.cms.CmsBuilderExecutorValve.process(CmsBuilderExecutorValve.java:213)
at org.objectledge.pipeline.SimplePipeline.process(SimplePipeline.java:66)
at org.objectledge.pipeline.ErrorHandlingPipeline.process(ErrorHandlingPipeline.java:100)
at org.objectledge.web.RequestTrackingValve.process(RequestTrackingValve.java:228)
at org.objectledge.pipeline.ConcurrencyControlValve.process(ConcurrencyControlValve.java:105)
at org.objectledge.web.dispatcher.PipelineHttpDispatcher.dispatch(PipelineHttpDispatcher.java:84)
at org.objectledge.web.LedgeServlet.service(LedgeServlet.java:130)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:228)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:216)
at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:283)
at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:767)
at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:697)
at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:889)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:686)
at java.lang.Thread.run(Thread.java:619)
"TP-Processor143":
at org.apache.velocity.runtime.resource.ResourceManagerImpl.getResource(ResourceManagerImpl.java:287)
- waiting to lock <0x00002aabd54204c0> (a org.apache.velocity.runtime.resource.ResourceManagerImpl)
at org.apache.velocity.runtime.RuntimeInstance.getTemplate(RuntimeInstance.java:1102)
at org.apache.velocity.runtime.RuntimeInstance.getTemplate(RuntimeInstance.java:1077)
at org.apache.velocity.runtime.VelocimacroFactory.initVelocimacro(VelocimacroFactory.java:196)
- locked <0x00002aabd5487e40> (a org.apache.velocity.runtime.VelocimacroFactory)
at org.apache.velocity.runtime.RuntimeInstance.init(RuntimeInstance.java:251)
- locked <0x00002aabd5487dd0> (a org.apache.velocity.runtime.RuntimeInstance)
at org.apache.velocity.app.VelocityEngine.init(VelocityEngine.java:116)
at org.objectledge.templating.velocity.VelocityTemplating.restart(VelocityTemplating.java:159)
at org.objectledge.modules.actions.templating.Restart.process(Restart.java:67)
at org.objectledge.web.mvc.actions.ActionExecutorValve.process(ActionExecutorValve.java:97)
at org.objectledge.pipeline.SimplePipeline.process(SimplePipeline.java:66)
at org.objectledge.pipeline.ErrorHandlingPipeline.process(ErrorHandlingPipeline.java:100)
at org.objectledge.web.RequestTrackingValve.process(RequestTrackingValve.java:228)
at org.objectledge.pipeline.ConcurrencyControlValve.process(ConcurrencyControlValve.java:105)
at org.objectledge.web.dispatcher.PipelineHttpDispatcher.dispatch(PipelineHttpDispatcher.java:84)
at org.objectledge.web.LedgeServlet.service(LedgeServlet.java:130)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:228)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:216)
at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:283)
at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:767)
at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:697)
at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:889)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:686)
at java.lang.Thread.run(Thread.java:619)

Found 1 deadlock

Aparrently, the deadlock is caused by poor lock management in Velocity codebase.
We can circumvent the problem by adding java.util.concurrent read/write locking to separate execution of VelocityEngine.getTemplate (shared) from VelocityEngine.init (exclusive)

Activity

Hide
Permalink
Rafał Krzewski added a comment -
A tentative fix applied. I considered introducing ReentrantReadWriteLock to separate restart() (exclusive) from all other operations (shared) but then I've noticed that I can initialize a new engine instance as a separate object and then atomically replace the current engine with new one. This should prevent the deadlock since separate instances of VMFactory and ResourceManager will be used by different threads.
Show
Rafał Krzewski added a comment - A tentative fix applied. I considered introducing ReentrantReadWriteLock to separate restart() (exclusive) from all other operations (shared) but then I've noticed that I can initialize a new engine instance as a separate object and then atomically replace the current engine with new one. This should prevent the deadlock since separate instances of VMFactory and ResourceManager will be used by different threads.

People

Vote (0)
Watch (0)

Dates

  • Created:
    Updated:
    Resolved:
Atlassian JIRA (v4.4.1#660-r161644) | Report a problem
Powered by a free Atlassian JIRA open source license for ObjectLedge . Try JIRA - bug tracking software for your team.