You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@struts.apache.org by Matthew Seaborn <Ma...@performgroup.com> on 2008/04/26 16:05:40 UTC

Struts 2 - Where does all the CPU go

In an attempt to find out where all the CPU cycles go I ran JProfiler against a request for a Struts 2 page containing a form with around 40 tags running under Tomcat 5.5, using SiteMesh for styling.

The details are below, but FreeMarker seems to be the primary guilty party.  Does anyone know how to get it to go faster, I already have the freemarker.properties file in WEB-INF/classes.

For those that are interested, the details.


Around 7% went to Tomcat and 4% to SiteMesh.


100.0% - 2,215 ms - 1 inv. org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run
  99.5% - 2,205 ms - 8 inv. ptv.http.HttpRequestInitialiserFilter.doFilter
   99.5% - 2,205 ms - 8 inv. ptv.http.HttpRequestInitialiserFilter.doFilter
    94.0% - 2,082 ms - 8 inv. javax.servlet.FilterChain.doFilter
     94.0% - 2,081 ms - 8 inv. com.opensymphony.module.sitemesh.filter.PageFilter.doFilter
      92.6% - 2,051 ms - 3 inv. com.opensymphony.module.sitemesh.filter.PageFilter.parsePage
       90.3% - 1,999 ms - 3 inv. javax.servlet.FilterChain.doFilter
        88.9% - 1,969 ms - 3 inv. com.opensymphony.xwork2.DefaultActionInvocation.invoke

Then about 4% went to the Struts 2 Interceptor stack. Of the remaining 85%, OGNL took about  15% (I estimate, all in) but the vast majority went to Freemarker; 67% consumed to render the tags.

84.8% 1,878 ms - 1 inv. /pages/vdp/rights/viewRight.jsp [org.apache.jsp.pages.vdp.rights.viewRight_jsp]
 67.2% - 1,488 ms - 23 inv. freemarker.template.Template.process
 7.7% - 171 ms - 95 inv. com.opensymphony.xwork2.util.OgnlValueStack.findValue(java.lang.String)
 4.2% - 94,134 µs - 108 inv. com.opensymphony.xwork2.util.TextParseUtil.translateVariables
 2.0% - 45,152 µs - 65 inv. com.opensymphony.xwork2.util.OgnlValueStack.findValue(java.lang.String, java.lang.Class)
 0.8% - 17,987 µs - 92 inv. com.opensymphony.xwork2.inject.ContainerImpl.inject
 0.3% - 6,119 µs - 63 inv. com.opensymphony.xwork2.util.TextUtils.htmlEncode
 0.2% - 4,390 µs - 23 inv. freemarker.template.SimpleHash.putAll
 0.2% - 3,542 µs - 384 inv. ognl.OgnlContext.get

I could find no particularly guilty party in FreeMarker, it just seemed to whittle the CPU away.  Some of it went to OGNL, but not much.

67.0% - 1,485 ms - 23 inv. freemarker.core.Environment.process
 66.9% - 1,482 ms - 23 inv. freemarker.core.Environment.visit
  66.9% - 1,482 ms - 23 inv. freemarker.core.MixedContent.accept
   66.9% - 1,481 ms - 108 inv. freemarker.core.Environment.visit
    62.0% - 1,374 ms - 59 inv. freemarker.core.Include.accept
     57.8% - 1,280 ms - 59 inv. freemarker.core.Environment.include
      57.7% - 1,277 ms - 59 inv. freemarker.core.Environment.visit
       57.6% - 1,276 ms - 59 inv. freemarker.core.MixedContent.accept
        57.4% - 1,271 ms - 504 inv. freemarker.core.Environment.visit
         23.7% - 525 ms - 49 inv. freemarker.core.Include.accept
         16.0% - 353 ms - 4 inv. freemarker.core.UnifiedCall.accept
         13.8% - 306 ms - 192 inv. freemarker.core.ConditionalBlock.accept
         1.7% - 37,064 µs - 40 inv. freemarker.core.DollarVariable.accept
         1.6% - 35,617 µs - 2 inv. freemarker.core.IfBlock.accept
         0.2% - 4,826 µs - 504 inv. freemarker.core.Environment.popElement
         0.1% - 2,696 µs - 504 inv. freemarker.core.Environment.pushElement
         0.1% - 1,513 µs - 155 inv. freemarker.core.TextBlock.accept
         0.0% - 108 µs - 61 inv. freemarker.core.Comment.accept
         0.0% - 36 µs - 1 inv. freemarker.core.PropertySetting.accept






Matthew Seaborn
Software Architect
t    +44(0) 208 484 0729
m  +44(0) 7949 465 142
e   matthew.seaborn@performgroup.com<ma...@performgroup.com>

[cid:image002.jpg@01C8A7AE.E9905EC0]
Sussex House
Plane Tree Crescent
Feltham, Middlesex, TW13 7HE
United Kingdom
http://www.performgroup.com/




________________________________________________________________________

CONFIDENTIALITY - This email and any files transmitted with it, are confidential, may be legally privileged and are intended solely for the use of the individual or entity to whom they are addressed. If this has come to you in error, you must not copy, distribute, disclose or use any of the information it contains. Please notify the sender immediately and delete them from your system.

SECURITY - Please be aware that communication by email, by its very nature, is not 100% secure and by communicating with Perform Group by email you consent to us monitoring and reading any such correspondence.

VIRUSES - Although this email message has been scanned for the presence of computer viruses, the sender accepts no liability for any damage sustained as a result of a computer virus and it is the recipient’s responsibility to ensure that email is virus free.

AUTHORITY - Any views or opinions expressed in this email are solely those of the sender and do not necessarily represent those of Perform Group.

COPYRIGHT - Copyright of this email and any attachments belongs to Perform Group, Companies House Registration number 6324278.

RE: Struts 2 - Where does all the CPU go

Posted by Matthew Seaborn <Ma...@performgroup.com>.
Where are certainly a number of calls through to OGNL within the Freemarker code, so it could still be that.

Unfortunately, I have already

<constant name="struts.freemarker.templatesCache" value="true" />

in my struts.xml

I don't see the WARNings you mention in my logs.

-----Original Message-----
From: Jeromy Evans [mailto:jeromy.evans@blueskyminds.com.au]
Sent: 27 April 2008 04:54
To: Struts Users Mailing List
Subject: Re: Struts 2 - Where does all the CPU go

Hi Matthew,

I'm surprised  that you can contribute more to FreeMarker than to than
Ognl. Perhaps FreeMarker is still masking the underlying problem as the
templates predominately call into the model setup by Struts and most of
that model is prepared via OGNL expressions.  OGNL does cache
expressions though and you would be reusing many of them.

Turn on freemarker template caching.  This is a cache within struts2,
rather than FreeMarker's own cache, that reuses the Template object
keyed by name rather than going to the template loader.

in struts.properties:
struts.freemarker.templatesCache=true

1.5 seconds within the template rendering is still huge though, even
with freemarker caching turned off. One of the templates must be calling
*something* slow in the struts 2 model.

I've always suspected that the guys below were eating up my cycles.

2008-04-27 13:26:58,413 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [org.apache.tiles.AttributeContext.STACK]
2008-04-27 13:26:58,414 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [org.apache.tiles.AttributeContext.STACK]
2008-04-27 13:26:58,414 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [org.apache.catalina.jsp_file]
2008-04-27 13:26:58,851 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [templateDir]
2008-04-27 13:26:58,852 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [templateDir]
2008-04-27 13:26:58,852 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [theme]
2008-04-27 13:26:58,853 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [theme]
2008-04-27 13:26:58,854 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [templateDir]
2008-04-27 13:26:58,854 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [templateDir]
2008-04-27 13:26:58,869 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [theme]
2008-04-27 13:26:58,870 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [theme]
2008-04-27 13:26:58,878 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [.freemarker.Request]
2008-04-27 13:26:58,878 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [.freemarker.RequestParameters]
2008-04-27 13:26:58,880 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [commands]
2008-04-27 13:26:59,036 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [property]
2008-04-27 13:26:59,044 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [property]
2008-04-27 13:26:59,074 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [templateDir]
2008-04-27 13:26:59,074 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [templateDir]
2008-04-27 13:26:59,074 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [theme]
2008-04-27 13:26:59,074 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [theme]
2008-04-27 13:26:59,076 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [templateDir]
2008-04-27 13:26:59,077 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [templateDir]
2008-04-27 13:26:59,077 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [theme]
2008-04-27 13:26:59,077 WARN  [http-8080-Processor24] [OgnlValueStack]
Could not find property [theme]


________________________________________________________________________

CONFIDENTIALITY - This email and any files transmitted with it, are confidential, may be legally privileged and are intended solely for the use of the individual or entity to whom they are addressed. If this has come to you in error, you must not copy, distribute, disclose or use any of the information it contains. Please notify the sender immediately and delete them from your system.

SECURITY - Please be aware that communication by email, by its very nature, is not 100% secure and by communicating with Perform Group by email you consent to us monitoring and reading any such correspondence.

VIRUSES - Although this email message has been scanned for the presence of computer viruses, the sender accepts no liability for any damage sustained as a result of a computer virus and it is the recipient�s responsibility to ensure that email is virus free.

AUTHORITY - Any views or opinions expressed in this email are solely those of the sender and do not necessarily represent those of Perform Group.

COPYRIGHT - Copyright of this email and any attachments belongs to Perform Group, Companies House Registration number 6324278.

---------------------------------------------------------------------
To unsubscribe, e-mail: user-unsubscribe@struts.apache.org
For additional commands, e-mail: user-help@struts.apache.org


Re: Struts 2 - Where does all the CPU go

Posted by Jeromy Evans <je...@blueskyminds.com.au>.
Matthew Seaborn wrote:
>
> In an attempt to find out where all the CPU cycles go I ran JProfiler 
> against a request for a Struts 2 page containing a form with around 40 
> tags running under Tomcat 5.5, using SiteMesh for styling.
>
>  
>
> The details are below, but FreeMarker seems to be the primary guilty 
> party.  Does anyone know how to get it to go faster, I already have 
> the freemarker.properties file in WEB-INF/classes.
>
>  
>
> For those that are interested, the details.
>
>  
>
>  
>
> Around 7% went to Tomcat and 4% to SiteMesh.
>
>  
>

Hi Matthew,

I'm surprised  that you can contribute more to FreeMarker than to than 
Ognl. Perhaps FreeMarker is still masking the underlying problem as the 
templates predominately call into the model setup by Struts and most of 
that model is prepared via OGNL expressions.  OGNL does cache 
expressions though and you would be reusing many of them.

Turn on freemarker template caching.  This is a cache within struts2, 
rather than FreeMarker's own cache, that reuses the Template object 
keyed by name rather than going to the template loader.

in struts.properties:
struts.freemarker.templatesCache=true

1.5 seconds within the template rendering is still huge though, even 
with freemarker caching turned off. One of the templates must be calling 
*something* slow in the struts 2 model.

I've always suspected that the guys below were eating up my cycles.

2008-04-27 13:26:58,413 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [org.apache.tiles.AttributeContext.STACK]
2008-04-27 13:26:58,414 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [org.apache.tiles.AttributeContext.STACK]
2008-04-27 13:26:58,414 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [org.apache.catalina.jsp_file]
2008-04-27 13:26:58,851 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [templateDir]
2008-04-27 13:26:58,852 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [templateDir]
2008-04-27 13:26:58,852 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [theme]
2008-04-27 13:26:58,853 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [theme]
2008-04-27 13:26:58,854 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [templateDir]
2008-04-27 13:26:58,854 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [templateDir]
2008-04-27 13:26:58,869 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [theme]
2008-04-27 13:26:58,870 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [theme]
2008-04-27 13:26:58,878 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [.freemarker.Request]
2008-04-27 13:26:58,878 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [.freemarker.RequestParameters]
2008-04-27 13:26:58,880 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [commands]
2008-04-27 13:26:59,036 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [property]
2008-04-27 13:26:59,044 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [property]
2008-04-27 13:26:59,074 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [templateDir]
2008-04-27 13:26:59,074 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [templateDir]
2008-04-27 13:26:59,074 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [theme]
2008-04-27 13:26:59,074 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [theme]
2008-04-27 13:26:59,076 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [templateDir]
2008-04-27 13:26:59,077 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [templateDir]
2008-04-27 13:26:59,077 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [theme]
2008-04-27 13:26:59,077 WARN  [http-8080-Processor24] [OgnlValueStack] 
Could not find property [theme]


---------------------------------------------------------------------
To unsubscribe, e-mail: user-unsubscribe@struts.apache.org
For additional commands, e-mail: user-help@struts.apache.org


Re: Struts 2 - Where does all the CPU go

Posted by Dave Newton <ne...@yahoo.com>.
IIRC you had said you already extracted the FreeMarker templates from the
core jar, right?

Dave

--- Matthew Seaborn <Ma...@performgroup.com> wrote:

> In an attempt to find out where all the CPU cycles go I ran JProfiler
> against a request for a Struts 2 page containing a form with around 40 tags
> running under Tomcat 5.5, using SiteMesh for styling.
> 
> The details are below, but FreeMarker seems to be the primary guilty party.
>  Does anyone know how to get it to go faster, I already have the
> freemarker.properties file in WEB-INF/classes.
> 
> For those that are interested, the details.
> 
> 
> Around 7% went to Tomcat and 4% to SiteMesh.
> 
> 
> 100.0% - 2,215 ms - 1 inv.
> org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run
>   99.5% - 2,205 ms - 8 inv. ptv.http.HttpRequestInitialiserFilter.doFilter
>    99.5% - 2,205 ms - 8 inv. ptv.http.HttpRequestInitialiserFilter.doFilter
>     94.0% - 2,082 ms - 8 inv. javax.servlet.FilterChain.doFilter
>      94.0% - 2,081 ms - 8 inv.
> com.opensymphony.module.sitemesh.filter.PageFilter.doFilter
>       92.6% - 2,051 ms - 3 inv.
> com.opensymphony.module.sitemesh.filter.PageFilter.parsePage
>        90.3% - 1,999 ms - 3 inv. javax.servlet.FilterChain.doFilter
>         88.9% - 1,969 ms - 3 inv.
> com.opensymphony.xwork2.DefaultActionInvocation.invoke
> 
> Then about 4% went to the Struts 2 Interceptor stack. Of the remaining 85%,
> OGNL took about  15% (I estimate, all in) but the vast majority went to
> Freemarker; 67% consumed to render the tags.
> 
> 84.8% 1,878 ms - 1 inv. /pages/vdp/rights/viewRight.jsp
> [org.apache.jsp.pages.vdp.rights.viewRight_jsp]
>  67.2% - 1,488 ms - 23 inv. freemarker.template.Template.process
>  7.7% - 171 ms - 95 inv.
> com.opensymphony.xwork2.util.OgnlValueStack.findValue(java.lang.String)
>  4.2% - 94,134 µs - 108 inv.
> com.opensymphony.xwork2.util.TextParseUtil.translateVariables
>  2.0% - 45,152 µs - 65 inv.
> com.opensymphony.xwork2.util.OgnlValueStack.findValue(java.lang.String,
> java.lang.Class)
>  0.8% - 17,987 µs - 92 inv.
> com.opensymphony.xwork2.inject.ContainerImpl.inject
>  0.3% - 6,119 µs - 63 inv.
> com.opensymphony.xwork2.util.TextUtils.htmlEncode
>  0.2% - 4,390 µs - 23 inv. freemarker.template.SimpleHash.putAll
>  0.2% - 3,542 µs - 384 inv. ognl.OgnlContext.get
> 
> I could find no particularly guilty party in FreeMarker, it just seemed to
> whittle the CPU away.  Some of it went to OGNL, but not much.
> 
> 67.0% - 1,485 ms - 23 inv. freemarker.core.Environment.process
>  66.9% - 1,482 ms - 23 inv. freemarker.core.Environment.visit
>   66.9% - 1,482 ms - 23 inv. freemarker.core.MixedContent.accept
>    66.9% - 1,481 ms - 108 inv. freemarker.core.Environment.visit
>     62.0% - 1,374 ms - 59 inv. freemarker.core.Include.accept
>      57.8% - 1,280 ms - 59 inv. freemarker.core.Environment.include
>       57.7% - 1,277 ms - 59 inv. freemarker.core.Environment.visit
>        57.6% - 1,276 ms - 59 inv. freemarker.core.MixedContent.accept
>         57.4% - 1,271 ms - 504 inv. freemarker.core.Environment.visit
>          23.7% - 525 ms - 49 inv. freemarker.core.Include.accept
>          16.0% - 353 ms - 4 inv. freemarker.core.UnifiedCall.accept
>          13.8% - 306 ms - 192 inv. freemarker.core.ConditionalBlock.accept
>          1.7% - 37,064 µs - 40 inv. freemarker.core.DollarVariable.accept
>          1.6% - 35,617 µs - 2 inv. freemarker.core.IfBlock.accept
>          0.2% - 4,826 µs - 504 inv. freemarker.core.Environment.popElement
>          0.1% - 2,696 µs - 504 inv. freemarker.core.Environment.pushElement
>          0.1% - 1,513 µs - 155 inv. freemarker.core.TextBlock.accept
>          0.0% - 108 µs - 61 inv. freemarker.core.Comment.accept
>          0.0% - 36 µs - 1 inv. freemarker.core.PropertySetting.accept
> 
> 
> 
> 
> 
> 
> Matthew Seaborn
> Software Architect
> t    +44(0) 208 484 0729
> m  +44(0) 7949 465 142
> e  
> matthew.seaborn@performgroup.com<ma...@performgroup.com>
> 
> [cid:image002.jpg@01C8A7AE.E9905EC0]
> Sussex House
> Plane Tree Crescent
> Feltham, Middlesex, TW13 7HE
> United Kingdom
> http://www.performgroup.com/
> 
> 
> 
> 
> ________________________________________________________________________
> 
> CONFIDENTIALITY - This email and any files transmitted with it, are
> confidential, may be legally privileged and are intended solely for the use
> of the individual or entity to whom they are addressed. If this has come to
> you in error, you must not copy, distribute, disclose or use any of the
> information it contains. Please notify the sender immediately and delete
> them from your system.
> 
> SECURITY - Please be aware that communication by email, by its very nature,
> is not 100% secure and by communicating with Perform Group by email you
> consent to us monitoring and reading any such correspondence.
> 
> VIRUSES - Although this email message has been scanned for the presence of
> computer viruses, the sender accepts no liability for any damage sustained
> as a result of a computer virus and it is the recipient’s responsibility to
> ensure that email is virus free.
> 
> AUTHORITY - Any views or opinions expressed in this email are solely those
> of the sender and do not necessarily represent those of Perform Group.
> 
> COPYRIGHT - Copyright of this email and any attachments belongs to Perform
> Group, Companies House Registration number 6324278.


---------------------------------------------------------------------
To unsubscribe, e-mail: user-unsubscribe@struts.apache.org
For additional commands, e-mail: user-help@struts.apache.org