Velocity
  1. Velocity
  2. VELOCITY-731

Velocity 1.6 performance is degraded by introduced toString() calls

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 1.6, 1.6.1, 1.6.2
    • Fix Version/s: 1.6.x, 1.7
    • Component/s: Engine
    • Labels:
      None
    • Environment:
      Apache Velocity 1.6.2

      Description

      As part of VELOCITY-531, r686428 introduced frequent calls to toString() just to check if toString() != null. If toString() implementations are slightly complex, and very frequently executed, these calls will degrade the site performance. Are they at all necessary? What kind of object would use null as a return value for toString()? Is it possible to remove these toString() calls from the velocity code again?

        Activity

        Jörgen Rydenius created issue -
        Hide
        Nathan Bubna added a comment -

        Velocity's long reliance on toString to render references means that toString() is expected to be called on references. This leads to a) the assumption that slow toString() methods will be called anyway and b) adaptation of fluent interfaces to take advantage of this behavior. The latter is the primary reason why we check whether toString() returns null. There are tools out there which resort to such behaviors because they are providing an API for Velocity, not for Java and did not feel constrained by Java conventions. Prior to 1.6 such null-returning behaved as expected in general VTL, but behaved differently in #if calls. r686428 evened this out. Since consistent behavior is generally more important than performance, and it is assumed that toString() will be called on most references anyway, this seemed the appropriate choice.

        For most people, 1.6 provided drastic improvements in performance. I'm sorry this was not the case for you. If you provide some examples of the slow spots for you, i can probably help you clean those up. For instance, if you were doing something like this:

        #if( $largeHashMap ) $largeHashMap.foobar #end

        It would slow down in 1.6, but you can circumvent the toString() in such a situation by doing:

        #if( !$largeHashMap.isEmpty() ) ...

        or if you are setting values, not just retrieving:

        #if( $largeHashMap.size() > -1 ) ...

        As to whether these toString() calls can be removed... they will not be removed in the 1.6 branch. Changing this back to the previous null handling in 1.7 could be done, but i am not yet convinced that the performance penalty is worse than the inconsistency of that behavior.

        In the 2.x branch, i do hope to eventually change this. I hope to alter Velocity to prioritize getAsString() methods and only use toString() when necessary. Once that is in place, Velocity should again insist that toString() never return null and act accordingly. But i'm not sure when that will happen, i've been swamped with other work for months now, and the end is not yet in sight.

        Show
        Nathan Bubna added a comment - Velocity's long reliance on toString to render references means that toString() is expected to be called on references. This leads to a) the assumption that slow toString() methods will be called anyway and b) adaptation of fluent interfaces to take advantage of this behavior. The latter is the primary reason why we check whether toString() returns null. There are tools out there which resort to such behaviors because they are providing an API for Velocity, not for Java and did not feel constrained by Java conventions. Prior to 1.6 such null-returning behaved as expected in general VTL, but behaved differently in #if calls. r686428 evened this out. Since consistent behavior is generally more important than performance, and it is assumed that toString() will be called on most references anyway, this seemed the appropriate choice. For most people, 1.6 provided drastic improvements in performance. I'm sorry this was not the case for you. If you provide some examples of the slow spots for you, i can probably help you clean those up. For instance, if you were doing something like this: #if( $largeHashMap ) $largeHashMap.foobar #end It would slow down in 1.6, but you can circumvent the toString() in such a situation by doing: #if( !$largeHashMap.isEmpty() ) ... or if you are setting values, not just retrieving: #if( $largeHashMap.size() > -1 ) ... As to whether these toString() calls can be removed... they will not be removed in the 1.6 branch. Changing this back to the previous null handling in 1.7 could be done, but i am not yet convinced that the performance penalty is worse than the inconsistency of that behavior. In the 2.x branch, i do hope to eventually change this. I hope to alter Velocity to prioritize getAsString() methods and only use toString() when necessary. Once that is in place, Velocity should again insist that toString() never return null and act accordingly. But i'm not sure when that will happen, i've been swamped with other work for months now, and the end is not yet in sight.
        Hide
        Jörgen Rydenius added a comment -

        I guess it is possible circumvent the slowdown by rewriting all velocity 1.5 code and/or java code. But it seems like a huge price to pay just because some tools generate objects with strange toString() return values. Our customers frequently use #if to check if something exists and act accordingly. It does not mean that the exact condition itself is going to be rendered later on.

        We tried to upgrade from 1.5 to 1.6.2 to gain performance and get rid of a few synchronization bottlenecks that troubled us. What we actually got was more than 100% worse performance. After patching the 1.6.2 jar with r686428 backed out, things turned to the better again, and after this we have a 20-30% performance improval over 1.5. So all the toString() calls had a huge impact for us. Lots of velocity code with conditions, in combination with some rather slow toString() implementaions on large objects. But toString() was never to be called on these objects during rendering, it was written to textually represent the object in a humanly readable way. Just like the java API for java.lang.Object says it should.

        I agree with the general intention of VELOCITY-531 and like consistent behaviour. I just wish that toString() wouldn't be called simply just for null checks. That is unnecessary, because toString() should never return null. All the java objects in the world are now paying the performance price for those tool generated objects with null returning toString() implementations you talked about.

        Nobody else noticed this issue while upgraing from 1.5 to 1.6?

        Show
        Jörgen Rydenius added a comment - I guess it is possible circumvent the slowdown by rewriting all velocity 1.5 code and/or java code. But it seems like a huge price to pay just because some tools generate objects with strange toString() return values. Our customers frequently use #if to check if something exists and act accordingly. It does not mean that the exact condition itself is going to be rendered later on. We tried to upgrade from 1.5 to 1.6.2 to gain performance and get rid of a few synchronization bottlenecks that troubled us. What we actually got was more than 100% worse performance. After patching the 1.6.2 jar with r686428 backed out, things turned to the better again, and after this we have a 20-30% performance improval over 1.5. So all the toString() calls had a huge impact for us. Lots of velocity code with conditions, in combination with some rather slow toString() implementaions on large objects. But toString() was never to be called on these objects during rendering, it was written to textually represent the object in a humanly readable way. Just like the java API for java.lang.Object says it should. I agree with the general intention of VELOCITY-531 and like consistent behaviour. I just wish that toString() wouldn't be called simply just for null checks. That is unnecessary, because toString() should never return null. All the java objects in the world are now paying the performance price for those tool generated objects with null returning toString() implementations you talked about. Nobody else noticed this issue while upgraing from 1.5 to 1.6?
        Hide
        Nathan Bubna added a comment -

        I'm not sure if anyone else has been bitten by this, but it is the first i recall being reported. And yeah, 100% worse vs 20-30% better is a massive price to pay for consistency in what is largely a corner-case. Perhaps this calls for a config switch. I don't like proliferation of config options for corner cases, but the reality that this is a behavior change that would essentially require some people to alter their existing templates to maintain performance seems justification enough.

        Perhaps a "directive.if.null.tostring = true" as the default, which you could set to false for the old behavior?

        Since you're already writing patches for yourself, is there any chance you'd be willing to write and contribute a patch for this?

        And, out of curiosity, what jdk are you running on?

        Show
        Nathan Bubna added a comment - I'm not sure if anyone else has been bitten by this, but it is the first i recall being reported. And yeah, 100% worse vs 20-30% better is a massive price to pay for consistency in what is largely a corner-case. Perhaps this calls for a config switch. I don't like proliferation of config options for corner cases, but the reality that this is a behavior change that would essentially require some people to alter their existing templates to maintain performance seems justification enough. Perhaps a "directive.if.null.tostring = true" as the default, which you could set to false for the old behavior? Since you're already writing patches for yourself, is there any chance you'd be willing to write and contribute a patch for this? And, out of curiosity, what jdk are you running on?
        Hide
        Jörgen Rydenius added a comment -

        The site run JDK 1.6.0_14, but a large portion of the objects that toString() was called upon were not JRE core classes.

        Making this configurable is a great solution. Even if the default is "directive.if.null.tostring = true" as you suggest. Recommending customers an alternative configuration feels much better than building custom velocity jar files.

        Right now I'm afraid I can not promise that I will be able to contribute a patch within the next few days.

        Show
        Jörgen Rydenius added a comment - The site run JDK 1.6.0_14, but a large portion of the objects that toString() was called upon were not JRE core classes. Making this configurable is a great solution. Even if the default is "directive.if.null.tostring = true" as you suggest. Recommending customers an alternative configuration feels much better than building custom velocity jar files. Right now I'm afraid I can not promise that I will be able to contribute a patch within the next few days.
        Hide
        Byron Foster added a comment -

        There was a discussion about this in VELOCITY-656

        In my case it comes up when using data objects where properties on the data object are intended to be rendered, but never the object itself. In these cases I use the toString() to dump a ton of information about the object, and maybe any related graph of objects, which is convenient for debugging.

        From what I know this behavior is only used by velocity tools, but I don't know of any other use cases for it. I also run with a patched version of Velocity with this behavior removed.

        Show
        Byron Foster added a comment - There was a discussion about this in VELOCITY-656 In my case it comes up when using data objects where properties on the data object are intended to be rendered, but never the object itself. In these cases I use the toString() to dump a ton of information about the object, and maybe any related graph of objects, which is convenient for debugging. From what I know this behavior is only used by velocity tools, but I don't know of any other use cases for it. I also run with a patched version of Velocity with this behavior removed.
        Hide
        Nathan Bubna added a comment -

        An embarrassing lapse of memory. Sorry, Byron. Yeah, we discussed this before. Clearly we are overdue for a proper solution. I wish i had done it then when i had more time.

        Jorgen, if you get to making a patch for this, that would be great. If not, i will eventually get to it. Things should, in theory, slow down for me a bit in a month or two.

        Show
        Nathan Bubna added a comment - An embarrassing lapse of memory. Sorry, Byron. Yeah, we discussed this before. Clearly we are overdue for a proper solution. I wish i had done it then when i had more time. Jorgen, if you get to making a patch for this, that would be great. If not, i will eventually get to it. Things should, in theory, slow down for me a bit in a month or two.
        Hide
        Jörgen Rydenius added a comment -

        Suggested patch that introduces the directive.if.tostring.nullcheck property. Any comments or improvements?

        Show
        Jörgen Rydenius added a comment - Suggested patch that introduces the directive.if.tostring.nullcheck property. Any comments or improvements?
        Jörgen Rydenius made changes -
        Field Original Value New Value
        Attachment configurable_tostring_nullcheck_patch.txt [ 12417264 ]
        Hide
        Nathan Bubna added a comment -

        The patch was great, especially since it included updates for the docs! I added a small testcase and dropped this in the 1.6 and 1.7 branches. I didn't put this in 2.0, since a different solution is intended there.

        Thanks for your help! I'm not sure if i'll find time to do another release soon, but perhaps you can talk Claude into it...

        Show
        Nathan Bubna added a comment - The patch was great, especially since it included updates for the docs! I added a small testcase and dropped this in the 1.6 and 1.7 branches. I didn't put this in 2.0, since a different solution is intended there. Thanks for your help! I'm not sure if i'll find time to do another release soon, but perhaps you can talk Claude into it...
        Nathan Bubna made changes -
        Status Open [ 1 ] Resolved [ 5 ]
        Fix Version/s 1.6.2 [ 12313574 ]
        Fix Version/s 1.7 [ 12313453 ]
        Resolution Fixed [ 1 ]
        Hide
        Jörgen Rydenius added a comment -

        Great news! A trivial detail though, shouldn't fix version be 1.6.3 on 1.6 branch since 1.6.2 is already out?

        Show
        Jörgen Rydenius added a comment - Great news! A trivial detail though, shouldn't fix version be 1.6.3 on 1.6 branch since 1.6.2 is already out?
        Hide
        Nathan Bubna added a comment -

        Yep, thanks.

        Show
        Nathan Bubna added a comment - Yep, thanks.
        Nathan Bubna made changes -
        Fix Version/s 1.6.x [ 12314172 ]
        Hide
        Nathan Bubna added a comment -

        Ok, now i've got it right...

        Show
        Nathan Bubna added a comment - Ok, now i've got it right...
        Nathan Bubna made changes -
        Fix Version/s 1.6.2 [ 12313574 ]
        Affects Version/s 1.6.2 [ 12313574 ]
        Affects Version/s 1.6.1 [ 12313544 ]
        Hide
        Jarkko Viinamäki added a comment -

        I know this is a closed issue but here goes anyway.

        I would expect that this fragment:

        #if( $foobar )
        ....

        merely tests whether the reference is valid (does the key exist in the context or does the path $foobar.name.Customer refer some non-null instance).

        But I would not expect it to call toString on that object (which should always return non-null value anyway).

        Thus I would prefer the old behaviour as the default.

        What are the use cases for this toString() == null check?

        Show
        Jarkko Viinamäki added a comment - I know this is a closed issue but here goes anyway. I would expect that this fragment: #if( $foobar ) .... merely tests whether the reference is valid (does the key exist in the context or does the path $foobar.name.Customer refer some non-null instance). But I would not expect it to call toString on that object (which should always return non-null value anyway). Thus I would prefer the old behaviour as the default. What are the use cases for this toString() == null check?
        Hide
        Nathan Bubna added a comment -

        Because Velocity originally decided to rely upon toString() solely, without providing a fallback like a TemplateString interface or a check for a getAsString method to allow alternative means of rendering, it became impossible to implement a simple alternator that could also handle null values. So any "smart" tool that wants to be asked about the validity of a reference (i.e. #if) has no recourse but to return null in toString to indicate that its current state is false/null/whatever. It is not possible for the "smart reference" to remove/re-add itself and allow the mere context presence check to communicate properly to #if. Again, the only recourse for such tools (and VelocityTools has them, as well as my apps) is to return null in toString in such cases.

        The choices i've seen here are:

        1: provide the config switch for those who have heavy toString calls to disable this
        2: return the previous inconsistent behavior that $foobar rendered null but #if( $foobar ) registered as true and have the switch go the other way for those who need consistent behavior
        3: enforce that all tools respect java convention to throw exceptions if toString returns null despite their usefulness within a different language (VTL), thus breaking several VelocityTools classes.
        4: implement a better solution (getAsString support)

        #4 is my eventual goal in 2.0, if not earlier
        #3 is unacceptable without changing major version number to indicate the BC break, but if we're gonna do that, then we might as well do #4
        #2 is not out of the question but quite distasteful, as we have already released a final version that supports consistent behavior here
        #1 seemed best for now

        Show
        Nathan Bubna added a comment - Because Velocity originally decided to rely upon toString() solely, without providing a fallback like a TemplateString interface or a check for a getAsString method to allow alternative means of rendering, it became impossible to implement a simple alternator that could also handle null values. So any "smart" tool that wants to be asked about the validity of a reference (i.e. #if) has no recourse but to return null in toString to indicate that its current state is false/null/whatever. It is not possible for the "smart reference" to remove/re-add itself and allow the mere context presence check to communicate properly to #if. Again, the only recourse for such tools (and VelocityTools has them, as well as my apps) is to return null in toString in such cases. The choices i've seen here are: 1: provide the config switch for those who have heavy toString calls to disable this 2: return the previous inconsistent behavior that $foobar rendered null but #if( $foobar ) registered as true and have the switch go the other way for those who need consistent behavior 3: enforce that all tools respect java convention to throw exceptions if toString returns null despite their usefulness within a different language (VTL), thus breaking several VelocityTools classes. 4: implement a better solution (getAsString support) #4 is my eventual goal in 2.0, if not earlier #3 is unacceptable without changing major version number to indicate the BC break, but if we're gonna do that, then we might as well do #4 #2 is not out of the question but quite distasteful, as we have already released a final version that supports consistent behavior here #1 seemed best for now
        Mark Thomas made changes -
        Workflow jira [ 12473621 ] Default workflow, editable Closed status [ 12551572 ]
        Mark Thomas made changes -
        Workflow Default workflow, editable Closed status [ 12551572 ] jira [ 12552457 ]
        Hide
        Colin Leroy added a comment -

        Hello,

        Just a heads up about this: it can slow down velosurf users a lot. For example if your model.xml defines an entity with a huge ROWSET attribute, like in:

        <entity name="CATEGORY">
        <attribute name="products" result="rowset/PRODUCT">select PRODUCT.* from PRODUCT where CAT_ID=<CAT_ID/></attribute>
        </entity>

        If you then do in a Velocity template:
        #set($category = $db.CATEGORY.fetch(1))
        #foreach($category.products)
        ...
        #end

        ##This seems constrained inline like this, but can happen when using macros for example
        #if($category)
        ...
        #end

        the #if($category) call ends up doing:
        TP-Processor96[1] where
        [1] velosurf.model.Attribute.query (Attribute.java:161)
        [2] velosurf.context.AttributeReference.iterator (AttributeReference.java:83)
        [3] java.util.AbstractCollection.toString (AbstractCollection.java:450)
        [4] java.lang.String.valueOf (String.java:2 615)
        [5] java.lang.StringBuffer.append (StringBuffer.java:220)
        [6] java.util.AbstractMap.toString (AbstractMap.java:598)
        [7] org.apache.velocity.runtime.parser.node.ASTReference.evaluate (ASTReference.java:547)
        [8] org.apache.velocity.runtime.parser.node.ASTExpression.evaluate (ASTExpression.java:62)
        [9] org.apache.velocity.runtime.parser.node.ASTIfStatement.render (ASTIfStatement.java:85)
        [10] org.apache.velocity.runtime.parser.node.ASTBlock.render (ASTBlock.java:72)
        [11] org.apache.velocity.runtime.parser.node.ASTIfStatement.render (ASTIfStatement.java:87)

        Setting directive.if.tostring.nullcheck = false changed the number of SQL requests done by some of our list pages, from 14000 to 1200.

        Show
        Colin Leroy added a comment - Hello, Just a heads up about this: it can slow down velosurf users a lot. For example if your model.xml defines an entity with a huge ROWSET attribute, like in: <entity name="CATEGORY"> <attribute name="products" result="rowset/PRODUCT">select PRODUCT.* from PRODUCT where CAT_ID=<CAT_ID/></attribute> </entity> If you then do in a Velocity template: #set($category = $db.CATEGORY.fetch(1)) #foreach($category.products) ... #end ##This seems constrained inline like this, but can happen when using macros for example #if($category) ... #end the #if($category) call ends up doing: TP-Processor96 [1] where [1] velosurf.model.Attribute.query (Attribute.java:161) [2] velosurf.context.AttributeReference.iterator (AttributeReference.java:83) [3] java.util.AbstractCollection.toString (AbstractCollection.java:450) [4] java.lang.String.valueOf (String.java:2 615) [5] java.lang.StringBuffer.append (StringBuffer.java:220) [6] java.util.AbstractMap.toString (AbstractMap.java:598) [7] org.apache.velocity.runtime.parser.node.ASTReference.evaluate (ASTReference.java:547) [8] org.apache.velocity.runtime.parser.node.ASTExpression.evaluate (ASTExpression.java:62) [9] org.apache.velocity.runtime.parser.node.ASTIfStatement.render (ASTIfStatement.java:85) [10] org.apache.velocity.runtime.parser.node.ASTBlock.render (ASTBlock.java:72) [11] org.apache.velocity.runtime.parser.node.ASTIfStatement.render (ASTIfStatement.java:87) Setting directive.if.tostring.nullcheck = false changed the number of SQL requests done by some of our list pages, from 14000 to 1200.
        Hide
        Christopher Schultz added a comment -

        Colin,

        So your bean has a toString method that issues a JDBC call? That just seems like a bad idea in the first place.

        There are other ways to check for the existence of a variable. For instance, instead of:

        #if($objectWithExpensiveToStringMethod)

        You can do this:

        #if($objectWithExpensiveToStringMethod.class)

        Every class has a getClass method (inherited from java.lang.Object) which will return null/false only if the object reference itself is null, so although it's less obvious what's going on (the .class on the end might raise some eyebrows), it gets the job done and doesn't hit your database.

        Show
        Christopher Schultz added a comment - Colin, So your bean has a toString method that issues a JDBC call? That just seems like a bad idea in the first place. There are other ways to check for the existence of a variable. For instance, instead of: #if($objectWithExpensiveToStringMethod) You can do this: #if($objectWithExpensiveToStringMethod.class) Every class has a getClass method (inherited from java.lang.Object) which will return null/false only if the object reference itself is null, so although it's less obvious what's going on (the .class on the end might raise some eyebrows), it gets the job done and doesn't hit your database.

          People

          • Assignee:
            Unassigned
            Reporter:
            Jörgen Rydenius
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development