Velocity
  1. Velocity
  2. VELOCITY-514

Rendering a template with inline macro concurrently causes VM error : Null AST

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 1.3.1, 1.4
    • Fix Version/s: 1.6
    • Component/s: Engine
    • Labels:
      None

      Description

      If a template with inline macro is rendered concurrently it prints the following errors in the log:

      ERROR [velocity] VM #myInlineMacro: error : too few arguments to macro. Wanted 3 got 0
      ERROR [velocity] VM error : myInlineMacro. Null AST

      and where the expected output of the inline macro is, it has the string values of the arguments passed to the macro in brackets
      eg:
      #myInlineMacro('Arg1' 'arg2' 'arg3')
      gives the following on above error
      (Arg1 arg2 arg3)

      1. VeloMacroTest.java
        3 kB
        Norbert Pomaroli
      2. slammer.vm
        1 kB
        Sam Chang
      3. recursive.vm
        0.2 kB
        Norbert Pomaroli
      4. nullAST.log
        7 kB
        Sam Chang
      5. macroSlammer-1.5.jar
        1.00 MB
        Sam Chang
      6. macroSlammer-1.4.jar
        1.06 MB
        Sam Chang
      7. macroSlammer.jar
        1.08 MB
        Sam Chang

        Activity

        Mark Thomas made changes -
        Workflow Default workflow, editable Closed status [ 12551515 ] jira [ 12552238 ]
        Mark Thomas made changes -
        Workflow jira [ 12395935 ] Default workflow, editable Closed status [ 12551515 ]
        Nathan Bubna made changes -
        Status Reopened [ 4 ] Resolved [ 5 ]
        Fix Version/s 1.5.1 [ 12312375 ]
        Resolution Fixed [ 1 ]
        Hide
        Nathan Bubna added a comment -

        I'm unable to reproduce this any longer. Seems to have been fixed by the fix for VELOCITY-607.

        Show
        Nathan Bubna added a comment - I'm unable to reproduce this any longer. Seems to have been fixed by the fix for VELOCITY-607 .
        Will Glass-Husain made changes -
        Fix Version/s 1.6 [ 12310290 ]
        Will Glass-Husain made changes -
        Fix Version/s 1.5 [ 12310253 ]
        Fix Version/s 1.5.1 [ 12312375 ]
        Hide
        Norbert Pomaroli added a comment -

        We also can reproduce this bug with both velocity-1.4 and velocity-1.5.
        I attached a simple test case with a recursive macro (see the two comments above).

        Our test environment:

        • Intel(R) Core(TM)2 Duo CPU based platform
        • SMP linux kernel (2.6.24)
        • Java HotSpot(TM) 64-Bit Server VM (build 1.5.0_06-b05, mixed mode)

        Maybe you need to run the test multiple times to reproduce the bug.

        Show
        Norbert Pomaroli added a comment - We also can reproduce this bug with both velocity-1.4 and velocity-1.5. I attached a simple test case with a recursive macro (see the two comments above). Our test environment: Intel(R) Core(TM)2 Duo CPU based platform SMP linux kernel (2.6.24) Java HotSpot(TM) 64-Bit Server VM (build 1.5.0_06-b05, mixed mode) Maybe you need to run the test multiple times to reproduce the bug.
        Norbert Pomaroli made changes -
        Attachment recursive.vm [ 12379249 ]
        Hide
        Norbert Pomaroli added a comment - - edited

        recursive.vm: Recursive template to be used with test VeloMacroTest to reproduce this bug.

        Show
        Norbert Pomaroli added a comment - - edited recursive.vm: Recursive template to be used with test VeloMacroTest to reproduce this bug.
        Norbert Pomaroli made changes -
        Attachment VeloMacroTest.java [ 12379248 ]
        Hide
        Norbert Pomaroli added a comment - - edited

        VeloMacroTest.java: Simple usecase to reproduce this bug with velocity-1.4 and velocity-1.5. Use with template recursive.vm

        Show
        Norbert Pomaroli added a comment - - edited VeloMacroTest.java: Simple usecase to reproduce this bug with velocity-1.4 and velocity-1.5. Use with template recursive.vm
        Hide
        Nathan Bubna added a comment -

        or any test case you can share, simple or not quite simple? (simple is preferred, but this sort of thing is going to be nigh impossible to fix or confirm fixed without being able to reproduce it)

        Show
        Nathan Bubna added a comment - or any test case you can share, simple or not quite simple? (simple is preferred, but this sort of thing is going to be nigh impossible to fix or confirm fixed without being able to reproduce it)
        Will Glass-Husain made changes -
        Resolution Fixed [ 1 ]
        Status Closed [ 6 ] Reopened [ 4 ]
        Assignee Henning Schmiedehausen [ henning ]
        Hide
        Will Glass-Husain added a comment -

        Thanks for the report. Any chance it's reproducible in a simple test case?

        Show
        Will Glass-Husain added a comment - Thanks for the report. Any chance it's reproducible in a simple test case?
        Hide
        Stephen Cresswell added a comment - - edited

        We're hitting this issue during our stress tests using Velocity 1.5

        2008-01-24 12:10:44,397 [resin-tcp-connection-tstrespub02:8080-49] ERROR com.gu.r2.common.velocity.logger.VelocityLogHandler - VM error requires. Null AST.

        Any chance of re-opening?

        Show
        Stephen Cresswell added a comment - - edited We're hitting this issue during our stress tests using Velocity 1.5 2008-01-24 12:10:44,397 [resin-tcp-connection-tstrespub02:8080-49] ERROR com.gu.r2.common.velocity.logger.VelocityLogHandler - VM error requires. Null AST. Any chance of re-opening?
        Henning Schmiedehausen made changes -
        Status Resolved [ 5 ] Closed [ 6 ]
        Hide
        Henning Schmiedehausen added a comment -

        Close all resolved issues for Engine 1.5 release.

        Show
        Henning Schmiedehausen added a comment - Close all resolved issues for Engine 1.5 release.
        Henning Schmiedehausen made changes -
        Status Reopened [ 4 ] Resolved [ 5 ]
        Resolution Fixed [ 1 ]
        Hide
        Henning Schmiedehausen added a comment -

        Issue is fixed.

        Show
        Henning Schmiedehausen added a comment - Issue is fixed.
        Hide
        Henning Schmiedehausen added a comment -

        Ok, so this is VELOCITY-24 . The fix went in between beta-1 and beta-2 and if he can not reproduce it with beta-2, then it is good. Resolving it for good.

        Show
        Henning Schmiedehausen added a comment - Ok, so this is VELOCITY-24 . The fix went in between beta-1 and beta-2 and if he can not reproduce it with beta-2, then it is good. Resolving it for good.
        Hide
        Will Glass-Husain added a comment -

        I thought Sam said this did not reoccur in beta 2?

        Show
        Will Glass-Husain added a comment - I thought Sam said this did not reoccur in beta 2?
        Henning Schmiedehausen made changes -
        Affects Version/s 1.4 [ 12310249 ]
        Henning Schmiedehausen made changes -
        Status Resolved [ 5 ] Reopened [ 4 ]
        Assignee Henning Schmiedehausen [ henning ]
        Resolution Fixed [ 1 ]
        Hide
        Henning Schmiedehausen added a comment -

        Put this on the "need to verify" stack for 1.5.1/1.6. If it is bogus, good. If it is not, fix it in the next release.

        Show
        Henning Schmiedehausen added a comment - Put this on the "need to verify" stack for 1.5.1/1.6. If it is bogus, good. If it is not, fix it in the next release.
        Hide
        Henning Schmiedehausen added a comment -

        This smells like VELOCITY-24. I'm scared that you claim to be able to reproduce this with beta1 and beta2, because the fix should already be in beta2. I can see nothing in between beta2 and the release that actually fixes this.

        Show
        Henning Schmiedehausen added a comment - This smells like VELOCITY-24 . I'm scared that you claim to be able to reproduce this with beta1 and beta2, because the fix should already be in beta2. I can see nothing in between beta2 and the release that actually fixes this.
        Hide
        Will Glass-Husain added a comment -

        Many thanks for taking the trouble to identify and report this issue with a test case. Glad we've already caught it!

        Show
        Will Glass-Husain added a comment - Many thanks for taking the trouble to identify and report this issue with a test case. Glad we've already caught it!
        Sam Chang made changes -
        Resolution Fixed [ 1 ]
        Status Open [ 1 ] Resolved [ 5 ]
        Fix Version/s 1.5 [ 12310253 ]
        Hide
        Sam Chang added a comment -

        This was reproducable on 1.3.1 and 1.4 but not in 1.5

        Show
        Sam Chang added a comment - This was reproducable on 1.3.1 and 1.4 but not in 1.5
        Sam Chang made changes -
        Affects Version/s 1.3.1 [ 12310251 ]
        Affects Version/s 1.4 [ 12310249 ]
        Sam Chang made changes -
        Attachment macroSlammer-1.5.jar [ 12350509 ]
        Attachment slammer.vm [ 12350510 ]
        Attachment macroSlammer-1.4.jar [ 12350508 ]
        Hide
        Sam Chang added a comment -

        The previously attached jar did not run independantly.
        Added macroSlammer-1.4.jar which uses velocity 1.4 with correct dependency and macroSlammer-1.5.jar using velocity 1.5 beta 2. You will also need slammer.vm in the same directory to run.

        It does appear to be fixed (or reoccur less often) in velocity 1.5 beta 2.

        cheers,
        Sam

        Show
        Sam Chang added a comment - The previously attached jar did not run independantly. Added macroSlammer-1.4.jar which uses velocity 1.4 with correct dependency and macroSlammer-1.5.jar using velocity 1.5 beta 2. You will also need slammer.vm in the same directory to run. It does appear to be fixed (or reoccur less often) in velocity 1.5 beta 2. cheers, Sam
        Hide
        Christopher Schultz added a comment -

        Replication of this thread does not require tons of threads fighting each other.

        The same thing happens (at least, with 1.4) when you define a recursive macro.

        Show
        Christopher Schultz added a comment - Replication of this thread does not require tons of threads fighting each other. The same thing happens (at least, with 1.4) when you define a recursive macro.
        Sam Chang made changes -
        Field Original Value New Value
        Attachment nullAST.log [ 12350506 ]
        Attachment macroSlammer.jar [ 12350505 ]
        Hide
        Sam Chang added a comment -

        Attached macroSlammer.jar which reproduces the errors by queuing up multiple threads to render from a velocity template file.
        Also attached nullAST.log with the errors

        Requirements:
        Java 1.5
        Multiple CPU's

        To run:
        java -jar macroSlammer.jar

        This will create velocity.log which contains the error. You may need to run it several times to reproduce.
        (I found it to be reproduceable atleast 1 in 2 tries)

        Show
        Sam Chang added a comment - Attached macroSlammer.jar which reproduces the errors by queuing up multiple threads to render from a velocity template file. Also attached nullAST.log with the errors Requirements: Java 1.5 Multiple CPU's To run: java -jar macroSlammer.jar This will create velocity.log which contains the error. You may need to run it several times to reproduce. (I found it to be reproduceable atleast 1 in 2 tries)
        Hide
        Will Glass-Husain added a comment -

        This might be fixed in Velocity 1.5-- we fixed a number of subtle bugs around concurrency and error reporting. There's a beta out, and a full release expected in a couple days. Would you mind downloading the 1.5 beta and see if this issue still exists?

        Show
        Will Glass-Husain added a comment - This might be fixed in Velocity 1.5-- we fixed a number of subtle bugs around concurrency and error reporting. There's a beta out, and a full release expected in a couple days. Would you mind downloading the 1.5 beta and see if this issue still exists?
        Sam Chang created issue -

          People

          • Assignee:
            Unassigned
            Reporter:
            Sam Chang
          • Votes:
            1 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development