Performance Testing

[Byron Foster <by...@base2.cc>]

I've added a simple benchmark harness in the experimental directory.   
While simple, it does test with multiple threads, vm libraries,  
multiple vm files.  Below are profiling results using jrat showing  
methods that consume the most time.

9.1% SimpleNode.literal()
8.6% StrBuilder.append(String)
8.5% ProxyVMContext.get(String)
7.0% ASTText.render(InternalContextAdapter,Writer)
5.8% EventHandlerUtil.referenceInsert(..)
5.6% InternalContextAdapterImpl.getAllowRendering()
5.0% ChainedInternalContextAdapter.getAllowRendering()
4.9% ASTReference.getVariableValue(Context,String)
3.1% AbstractContext.get(String)
3.0% InternalContextAdapterImpl.get(String)

The left column is the percentage of total time spent in the method. A  
few points to make from a quick investigation of these numbers.

First, the times resulting from SimpleNode.literal, StrBuilder.append  
(the top two) and EventHandlerUtil.referenceInsert are due to the  
following line in ASTReference.render:

value = EventHandlerUtil.referenceInsert(rsvc, context, literal(),  
value);

Which accounts for nearly 25% of the time, Ouch! Not to mention the  
many number of StrBuilder objects created. (StrBuilder is called from  
within literal()) We are always taking the hit for this call even if  
there is no event handler installed.  I havn't looked into it, but  
will probably just put a conditional around it.

The second issue is the getAllowRendering() methods which wraps all  
calls to the writer within the ASTNode renders and account for 11% of  
the time. I'm a little surprised by this because it just returns a  
member, but it may be due to the multiple layers of delegates and  
interfaces.  From what I can tell, the purpose of this method is to  
serve the #stop directive (which the documentation claims is for  
debugging).  I've always thought that #stop stopped execution of the  
script, but it doesn't, it continues executing the script and doesn't  
write anything to the writer, Yikes.  I wonder if this shouldn't be  
implemented like #break, by throwing an exception which is caught at  
the top.  Execution of the script would stop, and getAllowRendering  
could be removed.

I'll add issues for these.


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@velocity.apache.org
For additional commands, e-mail: dev-help@velocity.apache.org

Re: Performance Testing

[Nathan Bubna <nb...@gmail.com>]

Yeah, i noticed the EventHandlerUtil problem when Jarkko and i were
working on other performance issues.  I hadn't noticed
getAllowRendering() costing much, but i think changing the
implementation to be more like #break is a fantastic idea.  That makes
a lot of sense to me.

On Sat, Jan 3, 2009 at 12:16 PM, Byron Foster <by...@base2.cc> wrote:
> I've added a simple benchmark harness in the experimental directory.  While
> simple, it does test with multiple threads, vm libraries, multiple vm files.
>  Below are profiling results using jrat showing methods that consume the
> most time.
>
> 9.1% SimpleNode.literal()
> 8.6% StrBuilder.append(String)
> 8.5% ProxyVMContext.get(String)
> 7.0% ASTText.render(InternalContextAdapter,Writer)
> 5.8% EventHandlerUtil.referenceInsert(..)
> 5.6% InternalContextAdapterImpl.getAllowRendering()
> 5.0% ChainedInternalContextAdapter.getAllowRendering()
> 4.9% ASTReference.getVariableValue(Context,String)
> 3.1% AbstractContext.get(String)
> 3.0% InternalContextAdapterImpl.get(String)
>
> The left column is the percentage of total time spent in the method. A few
> points to make from a quick investigation of these numbers.
>
> First, the times resulting from SimpleNode.literal, StrBuilder.append (the
> top two) and EventHandlerUtil.referenceInsert are due to the following line
> in ASTReference.render:
>
> value = EventHandlerUtil.referenceInsert(rsvc, context, literal(), value);
>
> Which accounts for nearly 25% of the time, Ouch! Not to mention the many
> number of StrBuilder objects created. (StrBuilder is called from within
> literal()) We are always taking the hit for this call even if there is no
> event handler installed.  I havn't looked into it, but will probably just
> put a conditional around it.
>
> The second issue is the getAllowRendering() methods which wraps all calls to
> the writer within the ASTNode renders and account for 11% of the time. I'm a
> little surprised by this because it just returns a member, but it may be due
> to the multiple layers of delegates and interfaces.  From what I can tell,
> the purpose of this method is to serve the #stop directive (which the
> documentation claims is for debugging).  I've always thought that #stop
> stopped execution of the script, but it doesn't, it continues executing the
> script and doesn't write anything to the writer, Yikes.  I wonder if this
> shouldn't be implemented like #break, by throwing an exception which is
> caught at the top.  Execution of the script would stop, and
> getAllowRendering could be removed.
>
> I'll add issues for these.
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@velocity.apache.org
> For additional commands, e-mail: dev-help@velocity.apache.org
>
>

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@velocity.apache.org
For additional commands, e-mail: dev-help@velocity.apache.org