Details

    • Type: Bug Bug
    • Status: Open
    • Priority: Major Major
    • Resolution: Unresolved
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: Engine
    • Labels:
      None
    • Environment:
      Velocity 1.6.3

      Description

      I have the same issue as reported in VELOCITY-562, velocity hangs in method Parser.jj_scan_token(). I can reproduce it by running heavy load on my application for a few hours.

      Currently running 1.6.3, I looked at the issues fixed in 1.6.4, VELOCITY-718 seems not related, but I will now upgrade to 1.6.4 and see if the same happens again.

      The application is using velocity in up to 3 threads simultaneously, nothing is shared between threads, relevant stack traces from a thread dump are as follows, one thread is currently not inside velocity at all:

      "1334671070@qtp-2060763463-85" prio=6 tid=0x00000000181c5800 nid=0x6004 runnable [0x00000000110dd000]
      java.lang.Thread.State: RUNNABLE
      at org.apache.velocity.runtime.parser.Parser.jj_scan_token(Parser.java:3340)
      at org.apache.velocity.runtime.parser.Parser.jj_3R_56(Parser.java:2768)
      at org.apache.velocity.runtime.parser.Parser.jj_3R_29(Parser.java:3000)
      at org.apache.velocity.runtime.parser.Parser.jj_3_8(Parser.java:2834)
      at org.apache.velocity.runtime.parser.Parser.jj_3_7(Parser.java:2878)
      at org.apache.velocity.runtime.parser.Parser.jj_2_7(Parser.java:2560)
      at org.apache.velocity.runtime.parser.Parser.Reference(Parser.java:1317)
      at org.apache.velocity.runtime.parser.Parser.Statement(Parser.java:354)
      at org.apache.velocity.runtime.parser.Parser.IfStatement(Parser.java:1530)
      at org.apache.velocity.runtime.parser.Parser.Statement(Parser.java:346)
      at org.apache.velocity.runtime.parser.Parser.Directive(Parser.java:888)
      at org.apache.velocity.runtime.parser.Parser.Statement(Parser.java:373)
      at org.apache.velocity.runtime.parser.Parser.process(Parser.java:311)
      at org.apache.velocity.runtime.parser.Parser.parse(Parser.java:105)
      at org.apache.velocity.runtime.RuntimeInstance.parse(RuntimeInstance.java:1131)
      at org.apache.velocity.runtime.RuntimeInstance.parse(RuntimeInstance.java:1086)
      at org.apache.velocity.Template.process(Template.java:124)
      at org.apache.velocity.runtime.resource.ResourceManagerImpl.loadResource(ResourceManagerImpl.java:446)
      at org.apache.velocity.runtime.resource.ResourceManagerImpl.getResource(ResourceManagerImpl.java:354)
      at org.apache.velocity.runtime.RuntimeInstance.getTemplate(RuntimeInstance.java:1400)
      at org.apache.velocity.runtime.directive.Parse.render(Parse.java:198)
      at org.apache.velocity.runtime.parser.node.ASTDirective.render(ASTDirective.java:175)
      at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:336)
      at org.apache.velocity.Template.merge(Template.java:328)
      at org.apache.velocity.Template.merge(Template.java:235)

      "1946923020@qtp-2060763463-4" prio=6 tid=0x000000000c6dc000 nid=0x48a4 runnable [0x0000000013bcd000]
      java.lang.Thread.State: RUNNABLE
      at org.apache.velocity.runtime.parser.Parser.jj_scan_token(Parser.java:3340)
      at org.apache.velocity.runtime.parser.Parser.jj_3R_56(Parser.java:2768)
      at org.apache.velocity.runtime.parser.Parser.jj_3R_29(Parser.java:3000)
      at org.apache.velocity.runtime.parser.Parser.jj_3_8(Parser.java:2834)
      at org.apache.velocity.runtime.parser.Parser.jj_3_7(Parser.java:2878)
      at org.apache.velocity.runtime.parser.Parser.jj_2_7(Parser.java:2560)
      at org.apache.velocity.runtime.parser.Parser.Reference(Parser.java:1317)
      at org.apache.velocity.runtime.parser.Parser.Statement(Parser.java:354)
      at org.apache.velocity.runtime.parser.Parser.Directive(Parser.java:888)
      at org.apache.velocity.runtime.parser.Parser.Statement(Parser.java:373)
      at org.apache.velocity.runtime.parser.Parser.process(Parser.java:311)
      at org.apache.velocity.runtime.parser.Parser.parse(Parser.java:105)
      at org.apache.velocity.runtime.RuntimeInstance.parse(RuntimeInstance.java:1131)
      at org.apache.velocity.runtime.RuntimeInstance.parse(RuntimeInstance.java:1086)
      at org.apache.velocity.Template.process(Template.java:124)
      at org.apache.velocity.runtime.resource.ResourceManagerImpl.loadResource(ResourceManagerImpl.java:446)
      at org.apache.velocity.runtime.resource.ResourceManagerImpl.getResource(ResourceManagerImpl.java:354)
      at org.apache.velocity.runtime.RuntimeInstance.getTemplate(RuntimeInstance.java:1400)
      at org.apache.velocity.runtime.RuntimeInstance.getTemplate(RuntimeInstance.java:1380)
      at org.apache.velocity.runtime.VelocimacroFactory.initVelocimacro(VelocimacroFactory.java:202)

      • locked <0x00000000cd74bae8> (a org.apache.velocity.runtime.VelocimacroFactory)
        at org.apache.velocity.runtime.RuntimeInstance.init(RuntimeInstance.java:261)
      • locked <0x00000000cd950eb8> (a org.apache.velocity.runtime.RuntimeInstance)
        at org.apache.velocity.app.VelocityEngine.init(VelocityEngine.java:107)

        Issue Links

          Activity

          Hide
          Nathan Bubna added a comment -

          This seems likely to be a bug in JavaCC, though i can't be sure right now. Considering the difficulty of reproducing this (3 hours under load), please provide as much info as possible about the environment (OS, JVM, servlet engine, etc) and also your velocity.properties, if you change any from the defaults. It would be good to know parser pool size, resource loader, etc.

          Show
          Nathan Bubna added a comment - This seems likely to be a bug in JavaCC, though i can't be sure right now. Considering the difficulty of reproducing this (3 hours under load), please provide as much info as possible about the environment (OS, JVM, servlet engine, etc) and also your velocity.properties, if you change any from the defaults. It would be good to know parser pool size, resource loader, etc.
          Hide
          Steve Hale added a comment -

          I have encountered this issue in Velocity 1.6.4 as well. It occurrs after running a Janino ClassBodyEvaluator (with recompile) a few thousand times during a webpage request, then the hang occurs when Velocity tries to parse the template during the merge (since we have caching disabled in development). We do not know if Janino is leaving some object locked, or if garbage collection is affecting it, or if it is an internal Velocity issue. Here is our stacktrace from Eclipse captured after suspending the thread:
          Daemon Thread [doTask-6] (Suspended)
          Parser.jj_scan_token(int) line: 3340
          Parser.jj_3R_34() line: 2914
          Parser.jj_3R_20() line: 2941
          Parser.jj_3R_73() line: 2974
          Parser.jj_3R_67() line: 3021
          Parser.jj_3R_58() line: 3090
          Parser.jj_3R_31() line: 3075
          Parser.jj_3_11() line: 3085
          Parser.jj_2_11(int) line: 2588
          Parser.UnaryExpression() line: 2396
          Parser.MultiplicativeExpression() line: 2292
          Parser.AdditiveExpression() line: 2216
          Parser.RelationalExpression() line: 2084
          Parser.EqualityExpression() line: 2008
          Parser.ConditionalAndExpression() line: 1968
          Parser.ConditionalOrExpression() line: 1928
          Parser.Expression() line: 1875
          Parser.IfStatement() line: 1494
          Parser.Statement() line: 346
          Parser.process() line: 311
          Parser.parse(Reader, String) line: 105
          RuntimeInstance.parse(Reader, String, boolean) line: 1131
          RuntimeInstance.parse(Reader, String) line: 1086
          Template.process() line: 124
          ResourceManagerImpl.loadResource(String, int, String) line: 446
          ResourceManagerImpl.getResource(String, int, String) line: 354
          RuntimeInstance.getTemplate(String, String) line: 1400
          RuntimeInstance.getTemplate(String) line: 1380
          VelocityEngine.getTemplate(String) line: 401
          VMServlet.handleRequest(HttpServletRequest, HttpServletResponse, Context, Measurement, int) line: 853
          VMServlet.doRequest(HttpServletRequest, HttpServletResponse) line: 455
          VMServlet.doGet(HttpServletRequest, HttpServletResponse) line: 402
          VMServlet(HttpServlet).service(HttpServletRequest, HttpServletResponse) line: 627
          VMServlet(HttpServlet).service(ServletRequest, ServletResponse) line: 729
          ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line: 269
          ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 188
          InputScrubFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 130
          ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line: 215
          ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 188
          ContentCompressionFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 90
          ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line: 215
          ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 188
          SessionInterceptFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 60
          ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line: 215
          ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 188
          StandardWrapperValve.invoke(Request, Response) line: 213
          StandardContextValve.invoke(Request, Response) line: 172
          StandardHostValve.invoke(Request, Response) line: 127
          ErrorReportValve.invoke(Request, Response) line: 117
          StandardEngineValve.invoke(Request, Response) line: 108
          CoyoteAdapter.service(Request, Response) line: 174
          Http11Processor.process(InputStream, OutputStream) line: 879
          Http11Protocol$JmxHttp11ConnectionHandler(Http11BaseProtocol$Http11ConnectionHandler).processConnection(TcpConnection, Object[]) line: 665
          PoolTcpEndpoint.processSocket(Socket, TcpConnection, Object[]) line: 528
          LeaderFollowerWorkerThread.runIt(Object[]) line: 81
          ThreadPool$ControlRunnable.run() line: 689
          ThreadWithAttributes(Thread).run() line: not available

          Show
          Steve Hale added a comment - I have encountered this issue in Velocity 1.6.4 as well. It occurrs after running a Janino ClassBodyEvaluator (with recompile) a few thousand times during a webpage request, then the hang occurs when Velocity tries to parse the template during the merge (since we have caching disabled in development). We do not know if Janino is leaving some object locked, or if garbage collection is affecting it, or if it is an internal Velocity issue. Here is our stacktrace from Eclipse captured after suspending the thread: Daemon Thread [doTask-6] (Suspended) Parser.jj_scan_token(int) line: 3340 Parser.jj_3R_34() line: 2914 Parser.jj_3R_20() line: 2941 Parser.jj_3R_73() line: 2974 Parser.jj_3R_67() line: 3021 Parser.jj_3R_58() line: 3090 Parser.jj_3R_31() line: 3075 Parser.jj_3_11() line: 3085 Parser.jj_2_11(int) line: 2588 Parser.UnaryExpression() line: 2396 Parser.MultiplicativeExpression() line: 2292 Parser.AdditiveExpression() line: 2216 Parser.RelationalExpression() line: 2084 Parser.EqualityExpression() line: 2008 Parser.ConditionalAndExpression() line: 1968 Parser.ConditionalOrExpression() line: 1928 Parser.Expression() line: 1875 Parser.IfStatement() line: 1494 Parser.Statement() line: 346 Parser.process() line: 311 Parser.parse(Reader, String) line: 105 RuntimeInstance.parse(Reader, String, boolean) line: 1131 RuntimeInstance.parse(Reader, String) line: 1086 Template.process() line: 124 ResourceManagerImpl.loadResource(String, int, String) line: 446 ResourceManagerImpl.getResource(String, int, String) line: 354 RuntimeInstance.getTemplate(String, String) line: 1400 RuntimeInstance.getTemplate(String) line: 1380 VelocityEngine.getTemplate(String) line: 401 VMServlet.handleRequest(HttpServletRequest, HttpServletResponse, Context, Measurement, int) line: 853 VMServlet.doRequest(HttpServletRequest, HttpServletResponse) line: 455 VMServlet.doGet(HttpServletRequest, HttpServletResponse) line: 402 VMServlet(HttpServlet).service(HttpServletRequest, HttpServletResponse) line: 627 VMServlet(HttpServlet).service(ServletRequest, ServletResponse) line: 729 ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line: 269 ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 188 InputScrubFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 130 ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line: 215 ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 188 ContentCompressionFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 90 ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line: 215 ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 188 SessionInterceptFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 60 ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line: 215 ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 188 StandardWrapperValve.invoke(Request, Response) line: 213 StandardContextValve.invoke(Request, Response) line: 172 StandardHostValve.invoke(Request, Response) line: 127 ErrorReportValve.invoke(Request, Response) line: 117 StandardEngineValve.invoke(Request, Response) line: 108 CoyoteAdapter.service(Request, Response) line: 174 Http11Processor.process(InputStream, OutputStream) line: 879 Http11Protocol$JmxHttp11ConnectionHandler(Http11BaseProtocol$Http11ConnectionHandler).processConnection(TcpConnection, Object[]) line: 665 PoolTcpEndpoint.processSocket(Socket, TcpConnection, Object[]) line: 528 LeaderFollowerWorkerThread.runIt(Object[]) line: 81 ThreadPool$ControlRunnable.run() line: 689 ThreadWithAttributes(Thread).run() line: not available
          Hide
          Steve Hale added a comment -

          Update: If we run our app directly from Tomcat service, we do not hit this issue. However it seems very consistent when running Tomcat from Eclipse.

          Show
          Steve Hale added a comment - Update: If we run our app directly from Tomcat service, we do not hit this issue. However it seems very consistent when running Tomcat from Eclipse.

            People

            • Assignee:
              Unassigned
              Reporter:
              Dominik Stadler
            • Votes:
              1 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:

                Development