What causes a velocity Template.merge() failure? How does one avoid it?

Question

Our team has been experiencing a recurring problem with velocity templates. Upon rendering, some throw a RuntimeException with the message "Template.merge() failure - Unable to render Velocity Template, '/template.vm'". We have not been able to reproduce the problem and the documentation on the web is pretty insufficient. The problem is not consistently reproducible - the same templates whose rendering sometimes causes the error also manage to display without problems at other times. The Template class source code is also of little help. Thank you in advance.

---

Edit: Based on Nathan Bubna's response I need to clarify that we are using Velocity version 1.4.

---

Edit: Since it was pointed out that a stack trace would be beneficial, here it is:

2008-09-15 11:07:57,336 ERROR velocity - Template.merge() failure. The document is null, most likely due to parsing error. 2008-09-15 11:07:57,336 ERROR VelocityResult - Unable to render Velocity Template, '/search/[template-redacted].vm' java.lang.Exception: Template.merge() failure. The document is null, most likely due to parsing error. at org.apache.velocity.Template.merge(Template.java:277) at com.opensymphony.webwork.dispatcher.VelocityResult.doExecute(VelocityResult.java:91) at com.opensymphony.webwork.dispatcher.WebWorkResultSupport.execute(WebWorkResultSupport.java:109) at com.opensymphony.xwork.DefaultActionInvocation.executeResult(DefaultActionInvocation.java:258) at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:182) at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:35) at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:164) at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:35) at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:164) at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:35) at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:164) at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:35) at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:164) at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:35) at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:164) at com.opensymphony.xwork.interceptor.AroundInterceptor.intercept(AroundInterceptor.java:35) at com.opensymphony.xwork.DefaultActionInvocation.invoke(DefaultActionInvocation.java:164) at com.opensymphony.xwork.DefaultActionProxy.execute(DefaultActionProxy.java:116) at com.opensymphony.webwork.dispatcher.ServletDispatcher.serviceAction(ServletDispatcher.java:272) at com.opensymphony.webwork.dispatcher.ServletDispatcher.service(ServletDispatcher.java:237) at javax.servlet.http.HttpServlet.service(HttpServlet.java:802) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at com.opensymphony.module.sitemesh.filter.PageFilter.doFilter(PageFilter.java:39) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at org.nanocontainer.nanowar.webwork2.PicoObjectFactoryFilter.doFilter(PicoObjectFactoryFilter.java:46) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at org.nanocontainer.nanowar.ServletRequestContainerFilter.doFilter(ServletRequestContainerFilter.java:44) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at com.bostoncapital.stuyvesant.RememberUserNameFilter.doFilter(RememberUserNameFilter.java:30) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:482) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:526) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:825) at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:738) at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:526) at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684) at java.lang.Thread.run(Unknown Source)

Answer 1

I am working on the same bug right now, on our website.

It does appear to be a race condition: I can reproduce it consistently using multiple processes fetching the same page, but never reproduce it if I serialize the requests.

I am using velocity-1.5; I tried migrating to 1.6-beta1 but see other errors.

RESOLVED: see comments below

Answer 2

What version of Velocity are you using? There were some race conditions in old versions that caused this. Most were squashed in the Velocity 1.5 release. Though i would personally recommend using Velocity 1.6-beta1. It has vastly improved performance (memory and speed) and a lot of minor bug fixes that didn't make it into 1.5.

Edit: Since you say you are using 1.4, then, yes, i'm sure this is the race condition we fixed. Please consider upgrading. 1.6 is definitely your best bet, as it has the fix for your bug and improved performance. 1.6 final should be out very soon.

Answer 3

I have emailed the authors of the code to see if they can provide some insight. I'll make sure to share anything I've learned.

Answer 4

You need to get the full stack trace of the RuntimeException and its causes.

Please edit your answer to add that information.

Answer 5

Since the comments in the source already state this shouldn't happen, I think it's a bug in the Template software. Submit a bug report to whoever wrote it.